Re: [RavenDB] Unexpected end of content while loading JObject.

[Ayende Rahien]

Is this reproducable?

On Tue, Feb 22, 2011 at 6:19 AM, Simon <simon...@gmail.com> wrote:

I am getting this exception that seems to be triggered by some raven
background task

Using version 264

Unhandled Exception: System.Exception: Unexpected end of content while
loading JObject.
  at Newtonsoft.Json.Linq.JContainer.ReadTokenFrom(JsonReader r)
  at Newtonsoft.Json.Linq.JObject.Load(JsonReader reader)
  at Raven.Database.Json.JsonExtensions.ToJObject(Byte[] self)
  at
Raven.Storage.Esent.StorageActions.DocumentStorageActions.CompleteTransaction(Guid
txId, Action`1 perDocumentModified)
  at
Raven.Database.DocumentDatabase.<>c__DisplayClass4e.<Commit>b__4b(IStorageActionsAccessor
actions)
  at Raven.Storage.Esent.TransactionalStorage.ExecuteBatch(Action`1
action)
  at Raven.Storage.Esent.TransactionalStorage.Batch(Action`1 action)
  at Raven.Database.DocumentDatabase.Commit(Guid txId)
  at Raven.Client.Client.EmbededDatabaseCommands.Commit(Guid txId)
  at Raven.Client.Document.DocumentSession.Commit(Guid txId)
  at Raven.Client.Document.RavenClientEnlistment.Commit(Enlistment
enlistment)
  at System.Transactions.Oletx.OletxEnlistment.CommitRequest()
  at
System.Transactions.Oletx.OletxTransactionManager.ShimNotificationCallback(Object
state, Boolean timeout)
  at
System.Threading._ThreadPoolWaitOrTimerCallback.PerformWaitOrTimerCallback(Object
state, Boolean timedOut)

Not sure what other information I can give to help. Any pointers?

[Simon]

[Ayende Rahien]

FWIW, this seems to be called from a DTC commit, not ravendb background task

On Tue, Feb 22, 2011 at 6:19 AM, Simon <simon...@gmail.com> wrote:

[Simon Cropp]

Yes it is reproducible.
As in I can consistently get it to happen in my app

[Ayende Rahien]

Can you share the code?

[Simon Cropp]

I will attempt to repo it in an isolated project

[Michal]

Simon, did you manage to resolve this issue? We are getting the same
exception (in build 288) when we try to commit a transaction after
deleting documents. Our unit of work is being handled by NServiceBus
and hence the problem is linked to DTC. It is causing our whole data
store to be invalid and we are having to delete the Data folder to get
Raven up and running again. The exception is one thing, but we are
also a bit worried that it is causing the data store to crash so
badly.

I'm in the process of writing a failing test and will post the result
if I come up with anything meaningful.

On Feb 22, 8:37 am, Simon Cropp <simon.cr...@gmail.com> wrote:
> I will attempt to repo it in an isolated project
>
> On Tue, Feb 22, 2011 at 6:25 PM, Ayende Rahien <aye...@ayende.com> wrote:
> > Can you share the code?
>

> > On Tue, Feb 22, 2011 at 9:19 AM, Simon Cropp <simon.cr...@gmail.com> wrote:
>
> >> Yes it is reproducible.
> >> As in I can consistently get it to happen in my app
>
> >> On Tue, Feb 22, 2011 at 4:42 PM, Ayende Rahien <aye...@ayende.com> wrote:
> >> > Is this reproducable?
>

[Ayende Rahien]

Huh?! 

That should certainly not happen.

If you can reproduce that, I would dearly love to see the dat

[Simon Cropp]

Ayende

Here is a repo.

If you run it from the command line with
NServiceBus.Host.exe NserviceBus.InstallDtc NserviceBus.InstallMsmq TestNServiceBusSagaWithRavenDb.CustomProfile
You should get the exception message on the console.

If you run from within VS the process just crashes with no exception.

We are using some modified code based on the NSB contrib project
https://github.com/NServiceBus/NServiceBus-Contrib/tree/master/src/SagaPersisters/RavenDB

[Simon]

Oh and you can only run it once because the DB gets corrupted.

> We are using some modified code based on the NSB contrib projecthttps://github.com/NServiceBus/NServiceBus-Contrib/tree/master/src/Sa...
>
>  TestNServiceBusSagaWithRavenDb.7z.txt
> 3573KViewDownload

[Ayende Rahien]

Thanks, I'll look at it next week.

[nabils]

I have been getting this issue as well. I reverted straight back to
206 which is working fine so far. Will try to repro in 288 when I get
a chance. Also using NServiceBus and DTC by the way.

[ThorHalvor]

I also got the problem now with version 288.

If people get this problem with important data in the database :
REMEMBER TO USE RAVENSMUGGLER.EXE BEFORE THE SERVICE IS STOPPED..

The only thing i am doing is Session.Load - Session.Delete -
Session.SaveChanges. working with only 1 document.
When this is done in the transactionscope of a NServiceBus-handler
then the document i was working with get corrupted. If the RavenDb
service is stopped then it will never start up again and the whole
database is corrupted.

Error in system-events when the document was deleted:
<EventData>
<Data>Application: NServiceBus.Host.exe Framework Version:
v4.0.30319 Description: The process was terminated due to an unhandled
exception.
Exception Info: System.InvalidOperationException Stack: at
Raven.Client.Client.HttpJsonRequest.ReadStringInternal(System.Func`1<System.Net.WebResponse>)
at Raven.Client.Client.HttpJsonRequest.ReadResponseString() at
Raven.Client.Client.ServerClient.DirectCommit(System.Guid,
System.String) at Raven.Client.Client.ServerClient
+<>c__DisplayClass34.<Commit>b__33(System.String) at
Raven.Client.Client.ServerClient.TryOperation[[System.__Canon,
mscorlib, Version=4.0.0.0, Culture=neutral,
PublicKeyToken=b77a5c561934e089]]
(System.Func`2<System.String,System.__Canon>, System.String, Boolean,
System.__Canon ByRef) at
Raven.Client.Client.ServerClient.ExecuteWithReplication[[System.__Canon,
mscorlib, Version=4.0.0.0, Culture=neutral,
PublicKeyToken=b77a5c561934e089]](System.String,
System.Func`2<System.String,System.__Canon>) at
Raven.Client.Client.ServerClient.Commit(System.Guid) at
Raven.Client.Document.DocumentSession.Commit(System.Guid) at
Raven.Client.Document.RavenClientEnlistment.Commit(System.Transactions.Enlistment)
at System.Transactions.Oletx.OletxEnlistment.CommitRequest() at
System.Transactions.Oletx.OletxTransactionManager.ShimNotificationCallback(System.Object,
Boolean) at
System.Threading._ThreadPoolWaitOrTimerCallback.PerformWaitOrTimerCallback(System.Object,
Boolean)</Data>
</EventData>

Error when the RavenDb service was tried startet again:
<EventData>
<Data>Service cannot be started. System.Exception: Unexpected end of

content while loading JObject. at

Newtonsoft.Json.Linq.JContainer.ReadTokenFrom(JsonReader r) in d:
\Development\Releases\Json\Working\Src\Newtonsoft.Json\Linq
\JContainer.cs:line 683 at
Newtonsoft.Json.Linq.JObject.Load(JsonReader reader) in d:\Development
\Releases\Json\Working\Src\Newtonsoft.Json\Linq\JObject.cs:line 271 at
Raven.Database.Json.JsonExtensions.ToJObject(Byte[] self) in c:\Builds
\raven\Raven.Abstractions\Extensions\JsonExtensions.cs:line 48 at
Raven.Storage.Esent.StorageActions.DocumentStorageActions.CompleteTransaction(Guid
txId, Action`1 perDocumentModified) in c:\Builds\raven
\Raven.Storage.Esent\StorageActions\General.cs:line 223 at
Raven.Storage.Esent.StorageActions.DocumentStorageActions.RollbackTransaction(Guid
txId) in c:\Builds\raven\Raven.Storage.Esent\StorageActions
\General.cs:line 148 at
Raven.Database.Plugins.Builtins.PendingTransactionRecovery.<>c__DisplayClass1.<Execute>b__0(IStorageActionsAccessor
actions) in c:\Builds...</Data>
</EventData>


Thor Halvor
Oslo - Norway

[John Simons]

Hi Ayende,

Any news on this?

Cheers
John

[Ayende Rahien]

Yes,

I have reproduced this, and I know what is happening.

The problem is that I don't know how this is happening, or why.

The basic issue is that we are writing, in one case, 213 bytes into Esent, and we get 212 bytes back when we read them again.

I haven't been able to create an independent repro yet, and it is a bit hard for to to really believe what is going on even when I am seeing it.

If you have a simpler repro, I would greatly apprieciate it.

[Simon Cropp]

Ayende

To be honest I have no idea how to simplify the repo.

From the external point of view it could be a problem with any one of several black boxes (Json, Rave, NSB, Esent)

Perhaps it is worth raising this on the NSB and/or JSON discussion boards?? I am happy for you to re-post the repo

Happy to help in any way if you can give me some guidance.

Regarding "we are writing 213 bytes into Esent, and we get back 212". How is this possible? Is it a bug in the esent wrapper?

[Ayende Rahien]

Simon,

I am really not very sure how this is possible, to tell you the truth. The issue is likely with Esent, by the way, and maybe some interaction with the way we are writing there?

I am working on that, and I hope to have something more by next week.

I apologize for the long duration on this bug.

If this helps, I am pretty sure it is not a bug in our code, it doesn't seem to happen on 206, and that particular code path hasn't change in a while, but I think that we upgraded Esent.Interop.dll in the meanwhile.

I'll report here when I have anything of substance.

[DanPlaskon]

If it helps, we ran into this one too..and we do not make use of
NServiceBus.

We do, however, make use of TransactionScope and DTC to use Raven and
NHibernate together - so I'm thinking this is a more general problem
when using Raven with DTC, not NServerBus specifically.

On Mar 18, 2:59 am, Ayende Rahien <aye...@ayende.com> wrote:
> Simon,

> I am really not very sure *how *this is possible, to tell you the truth. The

> issue is likely with Esent, by the way, and maybe some interaction with the
> way we are writing there?
> I am working on that, and I hope to have something more by next week.
> I apologize for the long duration on this bug.
>
> If this helps, I am pretty sure it is not a bug in our code, it doesn't seem
> to happen on 206, and that particular code path hasn't change in a while,

> but I *think *that we upgraded Esent.Interop.dll in the meanwhile.

> I'll report here when I have anything of substance.
>
>
>
> On Fri, Mar 18, 2011 at 2:59 AM, Simon Cropp <simon.cr...@gmail.com> wrote:
> > Ayende
>
> > To be honest I have no idea how to simplify the repo.
>
> > From the external point of view it could be a problem with any one of
> > several black boxes (Json, Rave, NSB, Esent)
>
> > Perhaps it is worth raising this on the NSB and/or JSON discussion boards??
> > I am happy for you to re-post the repo
>
> > Happy to help in any way if you can give me some guidance.
>
> > Regarding "we are writing 213 bytes into Esent, and we get back 212". How

> > is this possible? Is it a bug in the esent wrapper?- Hide quoted text -
>
> - Show quoted text -

[Ayende Rahien]

I am actually thinking the issue is with promoted distributed transactions and Raven, I'll try to create a better repro next week.

[jag70jag70]

Just informing that our team also get this issue - we also use
NServiceBus and RavenDB.
I ran v206 before without noticing this issue, now I am running v288
which fails every time.

Per Eivind Jenssen

[Ayende Rahien]

Can we try to send me a repro from your end? I am trying to figure out exactly what is

On Fri, Mar 18, 2011 at 4:15 PM, DanPlaskon <dpla...@gmail.com> wrote:

[Ayende Rahien]

Hi guys,

Thanks to a lot of help from Rob Ashton, who claim to have done nothing, we now have a fix for this.

I'll have a full separate post of this in a bit, after I ensure that all the tests run properly.

[Simon Cropp]

great news Ayende

[Simon Cropp]

Do we win a prize for the most difficult bug to diagnose in Ravendb?

[Ayende Rahien]

I am not sure, the json immutability one was quite nasty, too. 

On the other hand, this one was