Proxy heartbeat causes warning log message (stream id -1)

[joao-r-reis]

Usually it is up to the client to set up heartbeats. The clients will only send heartbeats if no request is being sent through the connection.

In read only workloads, the clients will not send heartbeats but one of the connections in ZDM will become idle because reads are only being sent to the primary cluster. In this case the proxy will generate and send a heartbeat request to the secondary cluster connection.

This proxy generated heartbeat is causing warning log messages because when the response arrives the proxy is going through the normal workflow assuming that it is a response to a "normal" request.

There's no impact besides the annoying log messages because the stream id is being mapped to -1 by the cluster connector before the client handler starts processing it.

time="2023-08-16T18:55:40Z" level=warning msg="Could not find request context for stream id -1 received from TARGET-CONNECTOR. It either timed out or a protocol error occurred."

┆Issue is synchronized with this Jira Task by Unito
┆Components: Proxy
┆Issue Number: ZDM-597

[dpavlov-smartling]

Hello @joao-r-reis,

I am testing ZDM proxy configuration in preparation for the migration from Cassandra 3 cluster to Cassandra 4.
I have noticed the following error message that appears in the ZDM proxy logs:

level=error msg="[TARGET-CONNECTOR] Couldn't assign stream id to frame OpCode OPTIONS [0x05]: negative stream id: -1"

As far as I can see it is also related to heartbeats, because that error message is declared in

zdm-proxy/proxy/pkg/zdmproxy/clusterconn.go

Line 407 in 7e7b1f2

log.Errorf("[%v] Couldn't assign stream id to frame %v: %v", string(cc.connectorType), frame.Header.OpCode, err)

Do you think this is the same bug as you mentioned before?
ZDM proxies are configured to send read requests to Source cluster and Writes to both.
This is test cluster so, there isn't many writes.

I also didn't notice any impact on query execution or any kind of data loss.

Thanks,

[joao-r-reis]

Yeah if there's a period of time (default 30 seconds IIRC) where there aren't any writes then this will happen, it's annoying (log spam) but there's no impact besides that.

[dpavlov-smartling]

Thank you for the instance reply