Regarding DurabilityTimeoutCoercedEvent message

Hi all,

While going through the logs, I noticed the following log quite frequent:

class=com.couchbase.io thread=cb-events mtd=? line=? msg=[com.couchbase.io][DurabilityTimeoutCoercedEvent] Requested DurabilityTimeout outside range (1700-65535ms), using client side timeout of 300ms and server-side timeout of 1500ms. {"completed":true,"coreId":"redacted","idempotent":false,"lastChannelId":"A373C5E700000001/00000000EC593050","lastDispatchedFrom":"redacted","lastDispatchedTo":"redacted","requestId":31809,"requestType":"InsertRequest","retried":0,"service":{"bucket":"redacted","collection":"_default","documentId":"redacted","opaque":"0x78c4","scope":"_default","syncDurability":"MAJORITY","type":"kv","vbucket":56},"timeoutMs":300,"timings":{"dispatchMicros":1482,"encodingMicros":138,"totalDispatchMicros":1482,"totalServerMicros":1,"totalMicros":1699,"serverMicros":1}}

But I do not think that I set an explicit timeout for Durability and that I only set the query timeout. Example:

InsertOptions options = InsertOptions.insertOptions()
  .timeout(Duration.ofMillis(insertOperationTimeout)) // This timeout is for the query or query+durability?
  .durability(MAJORITY);

Could you please clarify?

Hi @yk010123 ,

InsertOptions options = InsertOptions.insertOptions()
  .timeout(Duration.ofMillis(insertOperationTimeout)) // This timeout is for the query or query+durability?
  .durability(MAJORITY);

The code you shared defines options for an “insert” request; nothing to do with query. Because you specified durability(DurabilityLevel), the timeout should be within the range 1700 milliseconds to 65535 milliseconds.

The log message tells you the requested timeout of 300 milliseconds is too short, and the client is adjusting the server-side timeout to fall within the valid range.

Thanks,
David

2 Likes

I am a little confused here.

For this log:

Requested DurabilityTimeout outside range (1700-65535ms), using client side timeout of 300ms and server-side timeout of 1500ms.

I requested 300ms, but we’re using 1500ms when the range is expected to be 1700-65535ms? How can the adjusted value be lower than the expected range?

Also, how does this work?

Is it as a separate ACK request or is it mandatory to close the write and return a status code back to the SDK request? ie: If the initial request succeeds but replication takes time, will that hold the request up to 1500ms?

I requested 300ms, but we’re using 1500ms when the range is expected to be 1700-65535ms? How can the adjusted value be lower than the expected range?

Sorry about that. Looking at the SDK code, there appears to be a ~10% grace period. I believe this is where the difference between 1700ms and 1500ms comes from. Apologies for the confusion. The log message could indeed be clearer.

Also, how does this work?

Is it as a separate ACK request or is it mandatory to close the write and return a status code back to the SDK request? ie: If the initial request succeeds but replication takes time, will that hold the request up to 1500ms?

The request is not complete until the durability requirement is satisfied, an error occurs, or the request times out. As you can imagine, a write with durability requirements takes longer than a plain old KV write request, since a plain old KV write completes as soon as the data is in memory on the node hosting the active version of a the partition.

More details here:

Thanks,
David

1 Like