Send two ScavengeDatabase at the time

[t3hnar]

Send two ScavengeDatabase at the time

[gregoryyoung]

I believe if scavenge is already running it just doesn't reply. Makes more
sense to reply as you say. I will take a look at that.

On Sun, Apr 6, 2014 at 5:27 PM, Yaroslav Klymko [email protected]:

Hi, when I send two ScavengeDatabase at the same time, I'm receiving
reply on the first one only. Correlation ids are different.

Expected behaviour: receive Scavenge InProgress as reply to the second
message.

Reply to this email directly or view it on GitHubhttps://github.com//issues/108
.

Le doute n'est pas une condition agréable, mais la certitude est absurde.

[gregoryyoung]

OK so I have been looking through this. It would appear that it will actually reply it will just queue the second request and run it after the first.

[t3hnar]

Hmmm strange, I can seen a totally different behaviour:
I'm receiving the first one, and then I'm not receiving the second one, tested with 10 seconds timeout.

[gregoryyoung]

How long does it take to handle the first one?

On Mon, Apr 7, 2014 at 4:52 PM, Yaroslav Klymko [email protected]:

Hmmm strange, I can seen a totally different behaviour:
I'm receiving the first one, and then I'm not receiving the second one,
tested with 10 seconds timeout.

Reply to this email directly or view it on GitHubhttps://github.com//issues/108#issuecomment-39731868
.

Le doute n'est pas une condition agréable, mais la certitude est absurde.

[gregoryyoung]

The relevant handler is here:

https://github.com/EventStore/EventStore/blob/master/src/EventStore/EventStore.Core/Services/Storage/StorageScavenger.cs#L54

On Mon, Apr 7, 2014 at 4:53 PM, Greg Young [email protected] wrote:

How long does it take to handle the first one?

On Mon, Apr 7, 2014 at 4:52 PM, Yaroslav Klymko [email protected]:

Hmmm strange, I can seen a totally different behaviour:
I'm receiving the first one, and then I'm not receiving the second one,
tested with 10 seconds timeout.

Reply to this email directly or view it on GitHubhttps://github.com//issues/108#issuecomment-39731868
.

Le doute n'est pas une condition agréable, mais la certitude est absurde.

Le doute n'est pas une condition agréable, mais la certitude est absurde.

[t3hnar]

this is my test

This is a full log

ScavengeDatabase,1c66d2d8-d710-4e22-b4d3-df2f9864884e,Some(UserCredentials(admin,***)))
ScavengeDatabase,1ab9a7d7-c737-4cbb-a9c2-a838cd460c13,Some(UserCredentials(admin,***)))
ScavengeDatabaseCompleted(0 milliseconds,0)),1c66d2d8-d710-4e22-b4d3-df2f9864884e)

[gregoryyoung]

What if anything is in the EventStore log?

On Mon, Apr 7, 2014 at 5:02 PM, Yaroslav Klymko [email protected]:

this is my testhttps://github.com/EventStore/EventStore.JVM/blob/3.0.0rc2/src/test/scala/eventstore/ScavengeITest.scala

This is a full log

ScavengeDatabase,1c66d2d8-d710-4e22-b4d3-df2f9864884e,Some(UserCredentials(admin,_)))
ScavengeDatabase,1ab9a7d7-c737-4cbb-a9c2-a838cd460c13,Some(UserCredentials(admin,_)))
ScavengeDatabaseCompleted(0 milliseconds,0)),1c66d2d8-d710-4e22-b4d3-df2f9864884e)

Reply to this email directly or view it on GitHubhttps://github.com//issues/108#issuecomment-39733130
.

Le doute n'est pas une condition agréable, mais la certitude est absurde.

[t3hnar]

Hm...

[11910,15,14:05:42.229] External TCP connection accepted: [Normal, 127.0.0.1:61147, L127.0.0.1:1113, {4c2e58aa-b0a8-432e-b385-e0dc0a7183b4}].
[11910,15,14:05:42.298] SCAVENGING: started scavenging of DB. Chunks count at start: 1. Options: alwaysKeepScavenged = False, mergeChunks = True
[11910,15,14:05:42.298] SCAVENGING: stopping scavenging pass due to non-completed TFChunk for position 0.
[11910,15,14:05:42.298] SCAVENGING: initial pass completed in 00:00:00.0001785.
[11910,15,14:05:42.298] SCAVENGING: stopping scavenging pass due to non-completed TFChunk for position 0.
[11910,15,14:05:42.298] SCAVENGING: merge pass #1 completed in 00:00:00.0000420. Nothing merged.
[11910,15,14:05:42.298] SCAVENGING: total time taken: 00:00:00.0003116, total space saved: 0.
[11910,06,14:05:42.358] ES TcpConnection closed [14:05:42.358: N127.0.0.1:61147, L127.0.0.1:1113, {4c2e58aa-b0a8-432e-b385-e0dc0a7183b4}]:
Received bytes: 37, Sent bytes: 28
Send calls: 1, callbacks: 1
Receive calls: 2, callbacks: 2
Close reason: [ConnectionReset] Socket receive error

[gregoryyoung]

Any follow up on this? Could the connection be getting closed before second finishes etc?

Sent from my iPhone

On 07 Apr 2014, at 15:07, Yaroslav Klymko [email protected] wrote:

Hm...

[11910,15,14:05:42.229] External TCP connection accepted: [Normal, 127.0.0.1:61147, L127.0.0.1:1113, {4c2e58aa-b0a8-432e-b385-e0dc0a7183b4}].
[11910,15,14:05:42.298] SCAVENGING: started scavenging of DB. Chunks count at start: 1. Options: alwaysKeepScavenged = False, mergeChunks = True
[11910,15,14:05:42.298] SCAVENGING: stopping scavenging pass due to non-completed TFChunk for position 0.
[11910,15,14:05:42.298] SCAVENGING: initial pass completed in 00:00:00.0001785.
[11910,15,14:05:42.298] SCAVENGING: stopping scavenging pass due to non-completed TFChunk for position 0.
[11910,15,14:05:42.298] SCAVENGING: merge pass #1 completed in 00:00:00.0000420. Nothing merged.
[11910,15,14:05:42.298] SCAVENGING: total time taken: 00:00:00.0003116, total space saved: 0.
[11910,06,14:05:42.358] ES TcpConnection closed [14:05:42.358: N127.0.0.1:61147, L127.0.0.1:1113, {4c2e58aa-b0a8-432e-b385-e0dc0a7183b4}]:
Received bytes: 37, Sent bytes: 28
Send calls: 1, callbacks: 1
Receive calls: 2, callbacks: 2
Close reason: [ConnectionReset] Socket receive error
—
Reply to this email directly or view it on GitHub.

[t3hnar]

Nope, connection closed after timeout error.
But I'll double check this evening

[gregoryyoung]

Hmm because it looks like a socket error. I can add some debugging code if you want re:socket codes etc

Sent from my iPhone

On 08 Apr 2014, at 14:00, Yaroslav Klymko [email protected] wrote:

Nope, connection closed after timeout error.

—
Reply to this email directly or view it on GitHub.

[gregoryyoung]

What's the size in bytes of your scavenge command and the event?

Sent from my iPhone

On 08 Apr 2014, at 14:00, Yaroslav Klymko [email protected] wrote:

Nope, connection closed after timeout error.

—
Reply to this email directly or view it on GitHub.

[t3hnar]

This can not be a socket error, as I can receive many HeartbeatResponses
Scavenge - MarkerByte + 0bytes

[gregoryyoung]

No I think the error is from after the test runs

On Tue, Apr 8, 2014 at 4:34 PM, Yaroslav Klymko [email protected]:

This can not be a socket error, as I can receive many "HeartbeatResponses"
Scavange - MarkerByte + 0bytes

Reply to this email directly or view it on GitHubhttps://github.com//issues/108#issuecomment-39847754
.

Le doute n'est pas une condition agréable, mais la certitude est absurde.

[gregoryyoung]

btw: in your log:

[11910,15,14:05:42.229] External TCP connection accepted: [Normal, 127.0.0.1:61147, L127.0.0.1:1113, {4c2e58aa-b0a8-432e-b385-e0dc0a7183b4}].
[11910,15,14:05:42.298] SCAVENGING: started scavenging of DB. Chunks count at start: 1. Options: alwaysKeepScavenged = False, mergeChunks = True
[11910,15,14:05:42.298] SCAVENGING: stopping scavenging pass due to non-completed TFChunk for position 0.
[11910,15,14:05:42.298] SCAVENGING: initial pass completed in 00:00:00.0001785.
[11910,15,14:05:42.298] SCAVENGING: stopping scavenging pass due to non-completed TFChunk for position 0.
[11910,15,14:05:42.298] SCAVENGING: merge pass #1 completed in 00:00:00.0000420. Nothing merged.
[11910,15,14:05:42.298] SCAVENGING: total time taken: 00:00:00.0003116, total space saved: 0.
[11910,06,14:05:42.358] ES TcpConnection closed [14:05:42.358: N127.0.0.1:61147, L127.0.0.1:1113, {4c2e58aa-b0a8-432e-b385-e0dc0a7183b4}]:
Received bytes: 37, Sent bytes: 28

The close is 60ms after the scavenge finshed (the whole connection is only held open for +- 200ms is this what you would expect given your code?

[anakryiko]

Here:
https://github.com/EventStore/EventStore/blob/master/src/EventStore/EventStore.Core/Services/Storage/StorageScavenger.cs#L49

There should be

else
{
message.Envelope.Reply(new )
}

Best regards,
Andrii Nakryiko

On Tue, Apr 8, 2014 at 7:16 AM, Greg Young [email protected] wrote:

btw: in your log:

[11910,15,14:05:42.229] External TCP connection accepted: [Normal,
127.0.0.1:61147, L127.0.0.1:1113, {4c2e58aa-b0a8-432e-b385-e0dc0a7183b4}].
[11910,15,14:05:42.298] SCAVENGING: started scavenging of DB. Chunks count
at start: 1. Options: alwaysKeepScavenged = False, mergeChunks = True
[11910,15,14:05:42.298] SCAVENGING: stopping scavenging pass due to
non-completed TFChunk for position 0.
[11910,15,14:05:42.298] SCAVENGING: initial pass completed in
00:00:00.0001785.
[11910,15,14:05:42.298] SCAVENGING: stopping scavenging pass due to
non-completed TFChunk for position 0.
[11910,15,14:05:42.298] SCAVENGING: merge pass #1https://github.com/EventStore/EventStore/issues/1completed in 00:00:00.0000420. Nothing merged.
[11910,15,14:05:42.298] SCAVENGING: total time taken: 00:00:00.0003116,
total space saved: 0.
[11910,06,14:05:42.358] ES TcpConnection closed [14:05:42.358:
N127.0.0.1:61147, L127.0.0.1:1113, {4c2e58aa-b0a8-432e-b385-e0dc0a7183b4}]:
Received bytes: 37, Sent bytes: 28

The close is 60ms after the scavenge finshed (the whole connection is only
held open for +- 200ms is this what you would expect given your code?

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/108#issuecomment-39852790
.

[gregoryyoung]

Resolved sending pull request