query field missing from some transactions

[mavendonovanhubbard]

For some reason the query field is missing from about half of our transactions. All the other fields are present and Maxwell does not seem to be logging any errors related to this. It only occurs in our production environment and we cannot reproduce it. We've tried to find any correlations to see what types of transactions are failing, whether it's certain tables or such but we haven't found any.

Below are the fields we get when the query field is missing

{
    "database":... ,
    "table": ...,
    "type": ...,
    "ts": ..,
    "xid": ...,
    "xoffset": ...,
    "position": ...,
    "push_ts": ...,
    "primary_key": ...,
    "primary_key_columns": ...,
    "data": { ... },
    "old": { ... }
}

Below is what we get when the query field is present

{
    "database":... ,
    "table": ...,
    "query": ...,
    "type": ...,
    "ts": ..,
    "xid": ...,
    "xoffset": ...,
    "position": ...,
    "push_ts": ...,
    "primary_key": ...,
    "primary_key_columns": ...,
    "data": { ... },
    "old": { ... }
}

[osheroff]

did you set the binlog_rows_query_log_events while the server was still running? any chance you have very-long-lived connections?

I ask because clients get the value of global variables (and it controls the binlog behavior) when they first establish their server connection.

[mavendonovanhubbard]

output_row_query is set to true. The maxwell process is running inside a kubernetes container so I killed and restarted the pod to turn it on. The pod restarts with some regularity so I doubt the problem is long lived connections. I imagine the problem isn't the output_row_query setting as it seems to be working for some transactions just not all.

[osheroff]

it's not the maxwell process that needs to restart but other connections -- the ones actually generating the transactions.

[mavendonovanhubbard]

I've narrowed down the problem to the BinlogConnectorReplicator.getTransactionRows function. The function loops through the events in each transaction and when it receives a ROWS_QUERY event it sets the currentQuery variable. Then when a write event occurs, such as a EXT_UPDATE_ROWS it uses that value to populate the query field on the RowMap objects. The problem is this happens it clears the currentQuery variable. This works fine for many transactions which have the events in an order:

1. ROWS_QUERY => Sets currentQuery
2. TABLE_MAP
3. EXT_UPDATE_ROWS => reads currentQuery then sets it to null

What I'm seeing in my production environment is many queries will call multiple sequential write events without calling ROWS_QUERY in-between.

1. ROWS_QUERY => Sets currentQuery
2. TABLE_MAP
3. EXT_UPDATE_ROWS => reads currentQuery then sets it to null
4. EXT_UPDATE_ROWS => currentQuery is null and so is the query field on the RowMap objects.

The solution is to not have the update case statement clear currentQuery. PR #1974

I've run it briefly in my production environment and it fixed the problem.

What is the purpose of setting currentQuery = null;?