Exception in BPlusTree

[zpqrtbnk]

See #4992, one that issue was fixed, the following happened:

System.ArgumentOutOfRangeException: Specified argument was out of the range of valid values. 
Parameter name: length
 at CSharpTest.Net.IO.TransactedCompoundFile.Write(UInt32 handle, Byte[] bytes, Int32 offset, Int32 length)
 at CSharpTest.Net.Storage.BTreeFileStoreV2.Update[T](IStorageHandle handleIn, ISerializer`1 serializer, T node)
 at CSharpTest.Net.Collections.BPlusTree`2.StorageCache.OnItemRemoved(KeyValuePair`2 item)
 at CSharpTest.Net.Collections.LurchTable`2.TryDequeue(Predicate`1 predicate, KeyValuePair`2& value)
 at CSharpTest.Net.Collections.BPlusTree`2.StorageCache.Flush()
 at CSharpTest.Net.Collections.BPlusTree`2.StorageCache.Commit()
 at CSharpTest.Net.Collections.BPlusTree`2.CommitChanges(Boolean requiresLock)
 at Umbraco.Web.PublishedCache.NuCache.ContentStore.Release(WriteLockInfo lockInfo, Boolean commit)
 at Umbraco.Web.PublishedCache.NuCache.ContentStore.Set(ContentNodeKit kit)
 at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService.NotifyLocked(IEnumerable`1 payloads, Boolean& draftChanged, Boolean& publishedChanged)
 at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService.Notify(JsonPayload[] payloads, Boolean& draftChanged, Boolean& publishedChanged)
 at Umbraco.Web.Cache.ContentCacheRefresher.Refresh(JsonPayload[] payloads)
 at Umbraco.Core.Sync.ServerMessengerBase.DeliverLocal[TPayload](ICacheRefresher refresher, TPayload[] payload)
 at Umbraco.Core.Sync.ServerMessengerBase.Deliver[TPayload](ICacheRefresher refresher, TPayload[] payload)
 at Umbraco.Core.Sync.ServerMessengerBase.PerformRefresh[TPayload](ICacheRefresher refresher, TPayload[] payload)
 at Umbraco.Web.Cache.DistributedCache.RefreshByPayload[TPayload](Guid refresherGuid, IEnumerable`1 payloads)
 at Umbraco.Web.Cache.DistributedCacheExtensions.RefreshContentCache(DistributedCache dc, TreeChange`1[] changes)
 at Umbraco.Web.Cache.DistributedCacheBinder.ContentService_TreeChanged(IContentService sender, EventArgs args)
 at Umbraco.Core.Events.EventDefinition`2.RaiseEvent()
 at Umbraco.Core.Events.QueuingEventDispatcher.ScopeExitCompleted()
 at Umbraco.Core.Events.QueuingEventDispatcherBase.ScopeExit(Boolean completed)
 at Umbraco.Core.Scoping.Scope.<>c__DisplayClass72_0.<RobustExit>b__1()
 at Umbraco.Core.Scoping.Scope.TryFinally(Int32 index, Action[] actions)
 at Umbraco.Core.Scoping.Scope.TryFinally(Int32 index, Action[] actions)
 at Umbraco.Core.Scoping.Scope.RobustExit(Boolean completed, Boolean onException)
 at Umbraco.Core.Scoping.Scope.DisposeLastScope()
 at Umbraco.Core.Scoping.Scope.Dispose()
 at Umbraco.Core.Services.Implement.ContentService.SaveAndPublish(IContent content, String culture, Int32 userId, Boolean raiseEvents)
 at cmdportal.com.Controllers.ContentController.ImportArticle(Object objarticle) 
 in C:\CMDSVN\Websites\Controllers\ContentController.cs:line 1459

[zpqrtbnk]

Infos:

It was running fine for more than an hour and the contents were created correclty, so the fix seems to be working. But then we got one error and that stopped the replication as it seems like Umbraco never returned with an error. Weird, maybe that issue is on our side or the error is just not bulbing up and stuck on SaveAndPublish. I have to check that one.

It contains a NuCache error, but I am sure if this error is related to the original one, we talk about here if it is a new one.

It is a new one.

[crick3t]

Morning, Just a quick update. We are still trying to find out what is happening. Seems like our replication hangs on the same content each time. We have identified that content and now trying to replicate it and find out what is so special about it. I will let you know the outcome.

The other information that can be useful is that, after this error happens Umbraco fails to boot, see the error message below.

Description: An unhandled exception occurred during the execution of the current web request. Please review the stack trace for more information about the error and where it originated in the code.

Exception Details: Umbraco.Core.Exceptions.BootFailedException: Boot failed: Umbraco cannot run. See Umbraco's log file for more details.

-> Umbraco.Core.Exceptions.BootFailedException: Boot failed.

-> System.ArgumentOutOfRangeException: Specified argument was out of the range of valid values.
Parameter name: length
  at CSharpTest.Net.IO.TransactedCompoundFile.Write(UInt32 handle, Byte[] bytes, Int32 offset, Int32 length)
  at CSharpTest.Net.Storage.BTreeFileStoreV2.Update[T](IStorageHandle handleIn, ISerializer`1 serializer, T node)
  at CSharpTest.Net.Collections.BPlusTree`2.StorageCache.OnItemRemoved(KeyValuePair`2 item)
  at CSharpTest.Net.Collections.LurchTable`2.TryDequeue(Predicate`1 predicate, KeyValuePair`2& value)
  at CSharpTest.Net.Collections.BPlusTree`2.StorageCache.Flush()
  at CSharpTest.Net.Collections.BPlusTree`2.StorageCache.Commit()
  at CSharpTest.Net.Collections.BPlusTree`2.CommitChanges(Boolean requiresLock)
  at CSharpTest.Net.Collections.BPlusTree`2..ctor(BPlusTreeOptions`2 ioptions)
  at Umbraco.Web.PublishedCache.NuCache.DataSource.BTree.GetTree(String filepath, Boolean exists)
  at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService..ctor(Options options, IMainDom mainDom, IRuntimeState runtime, ServiceContext serviceContext, IPublishedContentTypeFactory publishedContentTypeFactory, IdkMap idkMap, IPublishedSnapshotAccessor publishedSnapshotAccessor, IVariationContextAccessor variationContextAccessor, IUmbracoContextAccessor umbracoContextAccessor, ILogger logger, IScopeProvider scopeProvider, IDocumentRepository documentRepository, IMediaRepository mediaRepository, IMemberRepository memberRepository, IDefaultCultureAccessor defaultCultureAccessor, IDataSource dataSource, IGlobalSettings globalSettings, ISiteDomainHelper siteDomainHelper, IEntityXmlSerializer entitySerializer, IPublishedModelFactory publishedModelFactory, UrlSegmentProviderCollection urlSegmentProviders)
  at DynamicMethod(Object[] )
  at LightInject.ServiceContainer.<>c__DisplayClass150_0.<WrapAsFuncDelegate>b__0() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3798
  at LightInject.ServiceContainer.<>c__DisplayClass198_0.<EmitLifetime>b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657
  at LightInject.PerContainerLifetime.GetInstance(Func`1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169
  at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action`1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__1(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.EmitConstructorDependency(IEmitter emitter, Dependency dependency) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4158
  at LightInject.ServiceContainer.EmitConstructorDependencies(ConstructionInfo constructionInfo, IEmitter emitter, Action`1 decoratorTargetEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4120
  at LightInject.ServiceContainer.EmitNewInstanceUsingImplementingType(IEmitter emitter, ConstructionInfo constructionInfo, Action`1 decoratorTargetEmitMethod) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4080
  at LightInject.ServiceContainer.EmitNewInstance(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4034
  at LightInject.ServiceContainer.EmitNewInstanceWithDecorators(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3929
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__2(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action`1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3776
  at LightInject.ServiceContainer.<>c__DisplayClass198_0.<EmitLifetime>b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657
  at LightInject.PerContainerLifetime.GetInstance(Func`1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169
  at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action`1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__1(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.EmitConstructorDependency(IEmitter emitter, Dependency dependency) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4158
  at LightInject.ServiceContainer.EmitConstructorDependencies(ConstructionInfo constructionInfo, IEmitter emitter, Action`1 decoratorTargetEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4120
  at LightInject.ServiceContainer.EmitNewInstanceUsingImplementingType(IEmitter emitter, ConstructionInfo constructionInfo, Action`1 decoratorTargetEmitMethod) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4080
  at LightInject.ServiceContainer.EmitNewInstance(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4034
  at LightInject.ServiceContainer.EmitNewInstanceWithDecorators(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3929
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__2(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action`1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3776
  at LightInject.ServiceContainer.<>c__DisplayClass198_0.<EmitLifetime>b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657
  at LightInject.PerContainerLifetime.GetInstance(Func`1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169
  at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action`1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__1(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.EmitConstructorDependency(IEmitter emitter, Dependency dependency) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4158
  at LightInject.ServiceContainer.EmitConstructorDependencies(ConstructionInfo constructionInfo, IEmitter emitter, Action`1 decoratorTargetEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4120
  at LightInject.ServiceContainer.EmitNewInstanceUsingImplementingType(IEmitter emitter, ConstructionInfo constructionInfo, Action`1 decoratorTargetEmitMethod) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4080
  at LightInject.ServiceContainer.EmitNewInstance(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4034
  at LightInject.ServiceContainer.EmitNewInstanceWithDecorators(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3929
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__0(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4646
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action`1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3776
  at LightInject.ServiceContainer.CreateDelegate(Type serviceType, String serviceName, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4743
  at LightInject.ServiceContainer.CreateDefaultDelegate(Type serviceType, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4705
  at LightInject.ServiceContainer.GetInstance(Type serviceType) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3437
  at Umbraco.Core.Composing.LightInject.LightInjectContainer.GetInstance(Type type)
  at Umbraco.Core.Composing.ComponentCollectionBuilder.CreateItem(IFactory factory, Type itemType)
  at Umbraco.Core.Composing.CollectionBuilderBase`3.<>c__DisplayClass10_0.<CreateItems>b__0(Type x)
  at System.Linq.Enumerable.WhereSelectArrayIterator`2.MoveNext()
  at System.Linq.Buffer`1..ctor(IEnumerable`1 source)
  at System.Linq.Enumerable.ToArray[TSource](IEnumerable`1 source)
  at Umbraco.Core.Composing.CollectionBuilderBase`3.CreateItems(IFactory factory)
  at Umbraco.Core.Composing.ComponentCollectionBuilder.CreateItems(IFactory factory)
  at Umbraco.Core.Composing.CollectionBuilderBase`3.CreateCollection(IFactory factory)
  at Umbraco.Core.Composing.LightInject.LightInjectContainer.<>c__DisplayClass20_0`1.<Register>b__0(IServiceFactory f)
  at DynamicMethod(Object[] )
  at LightInject.ServiceContainer.<>c__DisplayClass150_0.<WrapAsFuncDelegate>b__0() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3798
  at LightInject.ServiceContainer.<>c__DisplayClass198_0.<EmitLifetime>b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657
  at LightInject.PerContainerLifetime.GetInstance(Func`1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169
  at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action`1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__1(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action`1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3776
  at LightInject.ServiceContainer.CreateDelegate(Type serviceType, String serviceName, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4743
  at LightInject.ServiceContainer.CreateDefaultDelegate(Type serviceType, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4705
  at LightInject.ServiceContainer.GetInstance(Type serviceType) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3437
  at Umbraco.Core.Composing.LightInject.LightInjectContainer.GetInstance(Type type)
  at Umbraco.Core.FactoryExtensions.GetInstance[T](IFactory factory)
  at Umbraco.Core.Runtime.CoreRuntime.Boot(IRegister register, DisposableTimer timer)

[zpqrtbnk]

Thanks for the update. Nice debbuging infos. If you can narrow it down to 1 content item that would be of course super precious!

[crick3t]

No luck... :(

The import dies at the same spot every time. It is not a multi threading issue as currently I am running it on only one thread and the same happens.

After importing more than 21k contents, dies with that length error.

I have checked the logs and what happens is:

• Adds a new content with a huge body text (a bit more than 1M characters), published, saved all fine
• Adds another content, longish (600k) body text size, created, published, then NuCache length error
• Tries to add another content, not too long body text (200k)), created, published and the app hangs
• After restarting the site I get the error above at boot

I have tried to import only those three contents into an empty database and it was successful, no errors, nothing, all fine.

Any tips? Something I could check in the database or logs. Any idea what could be too long? For the long content the data field in the cmsContentNu table shows 1,133,053 for DATALENGTH(data)/2.

Side note: probably not relevant, but when we were using Umbraco v7 all the, more than 33k, contents went in without any issues.

[crick3t]

I have tried to import only those three articles but it is working, so I think it is not about a special content.

Can be there some sort of limitation for number of content or the the length of all the contents combined?

Tomorrow, I will try to run the import by skipping the first 10 and see if it dies 10 contents latter. Otherwise I have run out of ideas... :-/

[zpqrtbnk]

Sorry I haven't been able to investigate deeper yet. There is definitively something wrong. Will definitively investigate.

Note: the stacktrace you posted above is the boot failed exception. It seems to indicate that the NuCache local file is corrupt. Now... when you say that importing "hangs" can you give me more details? What is happening? Do you have more details, a stacktrace, etc? Can you look at (and maybe share) Umbraco's log around that time?

[crick3t]

When I say hangs, I mean it does nothing any more. After the error the next content creation request comes in, it adds it to the database and then nothing.

I have attached the log file from today. Umbraco.txt

I changed the log level to Debug, so we may get more information about what is happening:

• 13:52:23, content was added successfully
• 13:52:23, ImportArticles failed, System.ArgumentOutOfRangeException: Specified argument was out of the range of valid values. Parameter name: length
• 13:52:24, Document has been published, Invoking refresher, and that's all After this nothing really, I tried to log in and check the logs.
• 13:58:43, I have restarted the website.
• 13:58:47, Umbraco.Core.Exceptions.BootFailedException: Boot failed. ---> System.ArgumentOutOfRangeException: Specified argument was out of the range of valid values. Parameter name: length In previous cases, I have tried to wait, nothing happens even after 2 hours.

And you were right, NuCache local file gets corrupted after the error. If I delete the NuCache db files the site comes back. I have also noticed there is a tlog file with the last content. The one that caused the error.

I was running this import in a way where I skipped the first 10 to see if the error occurs on the same content or 10 contents after that. The error seems to happen at the same content, which is weird, because it is fine if I import only that content and the few before that.

[zpqrtbnk]

So, the log contains:

2019-03-19 13:52:23,890 [P8960/D2/T54] ERROR  cmdportal.com.Controllers.ContentController - ImportArticles failed for Content ID 375138
System.ArgumentOutOfRangeException: Specified argument was out of the range of valid values.
Parameter name: length
   at CSharpTest.Net.IO.TransactedCompoundFile.Write(UInt32 handle, Byte[] bytes, Int32 offset, Int32 length)
   at CSharpTest.Net.Storage.BTreeFileStoreV2.Update[T](IStorageHandle handleIn, ISerializer`1 serializer, T node)
   at CSharpTest.Net.Collections.BPlusTree`2.StorageCache.OnItemRemoved(KeyValuePair`2 item)
   at CSharpTest.Net.Collections.LurchTable`2.TryDequeue(Predicate`1 predicate, KeyValuePair`2& value)
   at CSharpTest.Net.Collections.BPlusTree`2.StorageCache.Flush()
   at CSharpTest.Net.Collections.BPlusTree`2.StorageCache.Commit()
   at CSharpTest.Net.Collections.BPlusTree`2.CommitChanges(Boolean requiresLock)
   at Umbraco.Web.PublishedCache.NuCache.ContentStore.Release(WriteLockInfo lockInfo, Boolean commit)
   at Umbraco.Web.PublishedCache.NuCache.ContentStore.Set(ContentNodeKit kit)
   at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService.NotifyLocked(IEnumerable`1 payloads, Boolean& draftChanged, Boolean& publishedChanged)
   at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService.Notify(JsonPayload[] payloads, Boolean& draftChanged, Boolean& publishedChanged)
   at Umbraco.Web.Cache.ContentCacheRefresher.Refresh(JsonPayload[] payloads)
   at Umbraco.Core.Sync.ServerMessengerBase.DeliverLocal[TPayload](ICacheRefresher refresher, TPayload[] payload)
   at Umbraco.Core.Sync.ServerMessengerBase.Deliver[TPayload](ICacheRefresher refresher, TPayload[] payload)
   at Umbraco.Core.Sync.ServerMessengerBase.PerformRefresh[TPayload](ICacheRefresher refresher, TPayload[] payload)
   at Umbraco.Web.Cache.DistributedCache.RefreshByPayload[TPayload](Guid refresherGuid, IEnumerable`1 payloads)
   at Umbraco.Web.Cache.DistributedCacheExtensions.RefreshContentCache(DistributedCache dc, TreeChange`1[] changes)
   at Umbraco.Web.Cache.DistributedCacheBinder.ContentService_TreeChanged(IContentService sender, EventArgs args)
   at Umbraco.Core.Events.EventDefinition`2.RaiseEvent()
   at Umbraco.Core.Events.QueuingEventDispatcher.ScopeExitCompleted()
   at Umbraco.Core.Events.QueuingEventDispatcherBase.ScopeExit(Boolean completed)
   at Umbraco.Core.Scoping.Scope.<>c__DisplayClass72_0.<RobustExit>b__1()
   at Umbraco.Core.Scoping.Scope.TryFinally(Int32 index, Action[] actions)
   at Umbraco.Core.Scoping.Scope.TryFinally(Int32 index, Action[] actions)
   at Umbraco.Core.Scoping.Scope.RobustExit(Boolean completed, Boolean onException)
   at Umbraco.Core.Scoping.Scope.DisposeLastScope()
   at Umbraco.Core.Scoping.Scope.Dispose()
   at Umbraco.Core.Services.Implement.ContentService.SaveAndPublish(IContent content, String culture, Int32 userId, Boolean raiseEvents)
   at cmdportal.com.Controllers.ContentController.ImportArticle(Object objarticle) in C:\CMDSVN\Websites\cmdportal\cmdportal.com\cmdportal.com\Controllers\ContentController.cs:line 1579

And that would be the original error. It happens when writing stuff out to the local cache. And then, because we crash, the local cache is corrupt, hence the other exception your reported above (when reading stuff from the local cache).

So... we're making progress (kinda) - something breaks the local cache tool we are using, when writing changes. I am going to look into that tool's code to see what's going on. It could be that serializing the content you are inserting is... causing problems. But then as you mention, it's odd that add that single item works.

However - do I understand that it always fail on the same item?

[crick3t]

Yes, it always fails on the same spot And the good news is, I also got closer to the issue. (kinda)

What I think the issue is that we have a few contents with really-really long body content. Basically contents where you have an html table with 10 columns and hundreds of rows. The cells contain links, texts, etc. Top of that someone copied it from MS word, so each td has inline css to make it more fun. Now a content like this contains more than a million characters. e.g.: one td:

< td style="background: rgb(178, 206, 220) none repeat scroll 0% 0%; padding: 0.75pt;">< p align="center" style="text-align: center;" class="MsoNormal">< strong>< span style="font-size: 8pt; font-family: "Arial",sans-serif;">ISIN Code< /span>< /strong>< /p> < /td>

When I import it individually then it is working, but when I import 3 of these after each other at the same time it dies. I mean one thread creates 3 of these after each other in a loop.

My two cents: Can it be, that NuCache stores some of the content in the transaction file and when it flushes it out it just hits some limit? Maybe if you try it with a ridiculously long one like 5 million characters than it will die immediately.

[zpqrtbnk]

Oh uh... dunno how exactly you are importing things, but if each document is imported individually (ie you don't manage scopes) then each should be saved by the underlying cache, independently - that being said, that underlying cache may be optimizing things or ... I need to check.

A few millions chars is a lot ;-) I am going to try and reproduce.

BTW, really love the work you're doing here, it's super helpful and super clean/clear - thanks!

[crick3t]

Oh uh... dunno how exactly you are importing things, but if each document is imported individually...

Yes, no magic there. No scopes or anything like that. I was just thinking about it as I can see the same content twice in the NuCache.Content.tlog file after it crashes. Although only one content.

BTW, really love the work you're doing here, it's super helpful and super clean/clear - thanks!

Trying my best. Thank you.

[crick3t]

I was wrong, when I said it goes in individually. We have managed to replicate it, one content with a huge content body is enough to kill it. No need for multiple content. I just thought it was successful as the website is still responsive, but it does not mean anything, it fails to reboot and the next content cannot be published.

We will try to figure out where the limit is by decreasing the size of the content till it goes in without an error. (I think it is the NuCache local db file that has some sort of limit, while the SQL db stores it as ntext and that has no issues with the size of the content)

[crick3t]

So, I have created a loop where I create content and simply gradually expand size of the body content and create them one by one. When the content length reaches something like 541 000 characters, the error happens. To replicate just create a document type with a richtext editor and then create a content where the text is generated something like this:

StringBuilder content = new StringBuilder();
for (int i = 0; i < 5410; i++)
{
        content.Append("1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 1 2 3 4 5 6 7 8 9 0 "); //100 chars
}

I am not sure if it is the size of the content or the number of words that counts, but this one kills it every time. :)

Hope this helps.

[zpqrtbnk]

OK, I am just amazed by your detective work ;-) I have been hijacked on other topics and am somewhat ashamed I cannot answer to you faster. Anyways: going to try to repro later tonight with a content body of size > 541K chars - if I can repro, well then, will try to figure out what's going on.

[zpqrtbnk]

I am a bit slow here but haven't forgotten the issue. Managed to reproduce today, investigating.

[zpqrtbnk]

Turns out the file storage we are using has a block size that can be configured. I have created PR #5111 which adds a new app setting:

<add key="Umbraco.Web.PublishedCache.NuCache.BTree.BlockSize" value="4096" />

The default value is 4096 but you can use greater values - you have to use powers of two, lower than or equal to 65536 - so 8192, 16384, 32768 or 65536.

Don't know if you are comfortable building from a PR and testing? Want to try with differerent values and see if a value is ok for you? Bearing in mind that I'd go with the smallest value that fits.

[zpqrtbnk]

Had to re-do the PR due to stupid branch name, now is #5114

[crick3t]

Hi Stephan,

It's great that you managed to replicate the issue. I am busy with other things too at the moment, but I am happy to give it a try, when I will have a bit of a time.

After finding out what is causing the issue, I have added a filter to the import to skip those contents where the content body is too long (longer than 1 million char). With this work around and getting rid off the threads (previous issue) we were able to test our import, so it should work when we do it on live. Turned out we have less than 10 of those problematic contents and I was able to convince the management that we do not really need them. :)

I understand that, there are always limitations in every tool and code, but in my thinking a system should be able to handle exceptional cases gracefully (at least the known ones). Like in this case, I would prefer Umbraco to throw an exception, saying content too big and not allow anyone to add a content that breaks the whole system. My current worry is that, if we release the new CMS, then anyone can create a content accidentally (or on purpose) that causes the whole website to go down. Umbraco allows me to create a huge content, but then the cache dies the website cannot be booted after that, so the whole system breaks. Seems like the only solution in this case, is to delete the cache, find the content and delete it, before the cache kicks in again (which I guess happens when any content is updated/created/etc). This takes time while no one can access the website (clients or employees), which is a downtime where the company is loosing money and clients.

Anyway, I can play with your change and give it a shot, but I am not sure if I understand right. How would increasing the block size solve this issue? Wouldn't that just push the limit to somewhere else? Although, I am not a NuCache expert, so I believe you if you tell me it will be fine... :)

[zpqrtbnk]

I get your points, very valid. Yes, I'd love if you can give it a try - increasing the block size should let the cache support the large content items - but, as you mention, you'd have to experiment to find which block size is "enough" and nothing prevents ppl from creating an even larger content item later on and breaking things again.

So... this "workaround" is not an ideal situation - but the best I can do in a patch release (eg 8.0.3) to help you run your site - if you can confirm, even on a dev enviromnent, that a larger block size allows you to import the large documents, then we know we have (a) identified the problem and (b) found a work around.

I'd then close this short-termed issue, but would open another issue - as you mention, this is not really a long term solution.

[crick3t]

OK, I will give it a go, but just to double check. Should I use this one https://umbraco.visualstudio.com/Umbraco%20Cms/_build/results?buildId=19666 or I can use the latest one in the "Cms 8 Continuous"?

[zpqrtbnk]

the one your are linking to - the continous one does not contain the fix yet

[crick3t]

No, what I meant is the latest in that branch (or what ever it is called :) ). Anyway, I released that version and tested it. See my findings below.

First released it and tried to import the big ones and it failed as expected.

Then I have increased the block size to 8192 and restarted the website.

I got an error:

Exception Details: Umbraco.Core.Exceptions.BootFailedException: Boot failed: Umbraco cannot run. See Umbraco's log file for more details.
-> Umbraco.Core.Exceptions.BootFailedException: Boot failed.
-> System.IO.InvalidDataException: Found invalid data while decoding.
  at CSharpTest.Net.IO.TransactedCompoundFile.LoadSections(Stream stream)
  at CSharpTest.Net.IO.TransactedCompoundFile..ctor(Options options)
  at CSharpTest.Net.Storage.BTreeFileStoreV2..ctor(Options options)
  at CSharpTest.Net.Collections.BPlusTree`2.OptionsV2.CreateStorage()
  at CSharpTest.Net.Collections.BPlusTree`2.NodeCacheBase..ctor(BPlusTreeOptions`2 options)
  at CSharpTest.Net.Collections.BPlusTree`2.NodeCacheNone..ctor(BPlusTreeOptions`2 options)
  at CSharpTest.Net.Collections.BPlusTree`2..ctor(BPlusTreeOptions`2 ioptions)
  at Umbraco.Web.PublishedCache.NuCache.DataSource.BTree.GetTree(String filepath, Boolean exists)
  at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService..ctor(Options options, IMainDom mainDom, IRuntimeState runtime, ServiceContext serviceContext, IPublishedContentTypeFactory publishedContentTypeFactory, IdkMap idkMap, IPublishedSnapshotAccessor publishedSnapshotAccessor, IVariationContextAccessor variationContextAccessor, IUmbracoContextAccessor umbracoContextAccessor, ILogger logger, IScopeProvider scopeProvider, IDocumentRepository documentRepository, IMediaRepository mediaRepository, IMemberRepository memberRepository, IDefaultCultureAccessor defaultCultureAccessor, IDataSource dataSource, IGlobalSettings globalSettings, ISiteDomainHelper siteDomainHelper, IEntityXmlSerializer entitySerializer, IPublishedModelFactory publishedModelFactory, UrlSegmentProviderCollection urlSegmentProviders)
  at DynamicMethod(Object[] )
  at LightInject.ServiceContainer.<>c__DisplayClass150_0.<WrapAsFuncDelegate>b__0() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3798
  at LightInject.ServiceContainer.<>c__DisplayClass198_0.<EmitLifetime>b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657
  at LightInject.PerContainerLifetime.GetInstance(Func`1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169
  at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action`1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__1(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.EmitConstructorDependency(IEmitter emitter, Dependency dependency) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4158
  at LightInject.ServiceContainer.EmitConstructorDependencies(ConstructionInfo constructionInfo, IEmitter emitter, Action`1 decoratorTargetEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4120
  at LightInject.ServiceContainer.EmitNewInstanceUsingImplementingType(IEmitter emitter, ConstructionInfo constructionInfo, Action`1 decoratorTargetEmitMethod) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4080
  at LightInject.ServiceContainer.EmitNewInstance(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4034
  at LightInject.ServiceContainer.EmitNewInstanceWithDecorators(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3929
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__2(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action`1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3776
  at LightInject.ServiceContainer.<>c__DisplayClass198_0.<EmitLifetime>b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657
  at LightInject.PerContainerLifetime.GetInstance(Func`1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169
  at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action`1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__1(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.EmitConstructorDependency(IEmitter emitter, Dependency dependency) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4158
  at LightInject.ServiceContainer.EmitConstructorDependencies(ConstructionInfo constructionInfo, IEmitter emitter, Action`1 decoratorTargetEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4120
  at LightInject.ServiceContainer.EmitNewInstanceUsingImplementingType(IEmitter emitter, ConstructionInfo constructionInfo, Action`1 decoratorTargetEmitMethod) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4080
  at LightInject.ServiceContainer.EmitNewInstance(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4034
  at LightInject.ServiceContainer.EmitNewInstanceWithDecorators(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3929
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__2(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action`1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3776
  at LightInject.ServiceContainer.<>c__DisplayClass198_0.<EmitLifetime>b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657
  at LightInject.PerContainerLifetime.GetInstance(Func`1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169
  at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action`1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__1(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.EmitConstructorDependency(IEmitter emitter, Dependency dependency) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4158
  at LightInject.ServiceContainer.EmitConstructorDependencies(ConstructionInfo constructionInfo, IEmitter emitter, Action`1 decoratorTargetEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4120
  at LightInject.ServiceContainer.EmitNewInstanceUsingImplementingType(IEmitter emitter, ConstructionInfo constructionInfo, Action`1 decoratorTargetEmitMethod) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4080
  at LightInject.ServiceContainer.EmitNewInstance(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4034
  at LightInject.ServiceContainer.EmitNewInstanceWithDecorators(ServiceRegistration serviceRegistration, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3929
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__0(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4646
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action`1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3776
  at LightInject.ServiceContainer.CreateDelegate(Type serviceType, String serviceName, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4743
  at LightInject.ServiceContainer.CreateDefaultDelegate(Type serviceType, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4705
  at LightInject.ServiceContainer.GetInstance(Type serviceType) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3437
  at Umbraco.Core.Composing.LightInject.LightInjectContainer.GetInstance(Type type)
  at Umbraco.Core.Composing.ComponentCollectionBuilder.CreateItem(IFactory factory, Type itemType)
  at Umbraco.Core.Composing.CollectionBuilderBase`3.<>c__DisplayClass10_0.<CreateItems>b__0(Type x)
  at System.Linq.Enumerable.WhereSelectArrayIterator`2.MoveNext()
  at System.Linq.Buffer`1..ctor(IEnumerable`1 source)
  at System.Linq.Enumerable.ToArray[TSource](IEnumerable`1 source)
  at Umbraco.Core.Composing.CollectionBuilderBase`3.CreateItems(IFactory factory)
  at Umbraco.Core.Composing.ComponentCollectionBuilder.CreateItems(IFactory factory)
  at Umbraco.Core.Composing.CollectionBuilderBase`3.CreateCollection(IFactory factory)
  at Umbraco.Core.Composing.LightInject.LightInjectContainer.<>c__DisplayClass20_0`1.<Register>b__0(IServiceFactory f)
  at DynamicMethod(Object[] )
  at LightInject.ServiceContainer.<>c__DisplayClass150_0.<WrapAsFuncDelegate>b__0() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3798
  at LightInject.ServiceContainer.<>c__DisplayClass198_0.<EmitLifetime>b__1() in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4657
  at LightInject.PerContainerLifetime.GetInstance(Func`1 createInstance, Scope scope) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 6169
  at LightInject.ServiceContainer.EmitLifetime(ServiceRegistration serviceRegistration, Action`1 emitMethod, IEmitter emitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4656
  at LightInject.ServiceContainer.<>c__DisplayClass197_0.<ResolveEmitMethod>b__1(IEmitter methodSkeleton) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4649
  at LightInject.ServiceContainer.<>c__DisplayClass153_0.<CreateEmitMethodWrapper>b__0(IEmitter ms) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3856
  at LightInject.ServiceContainer.CreateDynamicMethodDelegate(Action`1 serviceEmitter) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3776
  at LightInject.ServiceContainer.CreateDelegate(Type serviceType, String serviceName, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4743
  at LightInject.ServiceContainer.CreateDefaultDelegate(Type serviceType, Boolean throwError) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 4705
  at LightInject.ServiceContainer.GetInstance(Type serviceType) in C:\projects\lightinject\src\LightInject\LightInject.cs:line 3437
  at Umbraco.Core.Composing.LightInject.LightInjectContainer.GetInstance(Type type)
  at Umbraco.Core.FactoryExtensions.GetInstance[T](IFactory factory)
  at Umbraco.Core.Runtime.CoreRuntime.Boot(IRegister register, DisposableTimer timer)

System.NullReferenceException: Object reference not set to an instance of an object.
   at Umbraco.Web.PublishedCache.NuCache.PublishedSnapshotService.<.ctor>b__25_6()
   at Umbraco.Core.MainDom.OnSignal(String source)

I guess NuCache cannot really handle the change... :)

I have deleted the Temp files and restarted the site. This time it came up.

Tried to import the big contents again and all of them worked. Even the one with more than 2M chars. I have tried to edit and publish it in the back office and it was a bit slow (obviously), but it was working fine.

So, yes, I can confirm this is a good work around, just make a note about the fact that the temp files have to be deleted when the block size had been changed. Otherwise the website would not boot.

[zpqrtbnk]

Many thanks for testing! Next steps:

• this solution is going to be merged into the next release, with a comment to indicate that the cache must be rebuilt whenever the block size is changed
• I'll create a longer-term issue to deal with it in a friendlier way - as you wrote, this should be automatic

[zpqrtbnk]

New issue is #5150, now moving this issue to review.

Reviewers: please note that if you change the block size, you have to rebuild the NuCache else you'll get exceptions. But basically, it's been reviewed already and works - just do a code review and ensure a normal site still works.

Also, this is an 8.0.x thing - please merge to v8/dev AND cherry pick to v8/8.0

[HarryAmmon]

Thanks, this thread helped me resolve an issue with an Umbraco 8.1.6 site not booting after migrating from 7.15.7. Thanks for the help!