From 35b8c7670385417e37ed79122aae07ab6b398667 Mon Sep 17 00:00:00 2001 From: Salil Chandra Date: Mon, 18 Nov 2024 15:44:27 -0500 Subject: [PATCH] Warn if adjusting long col name once per fp Signed-off-by: Salil Chandra --- db/db_fingerprint.c | 17 +++++++++++++++++ db/sql.h | 6 +++++- db/sqlinterfaces.c | 17 +++++++++++++++++ plugins/newsql/newsql.c | 15 ++++++++++++--- tests/column_names_length.test/runit | 26 ++++++++++++++++++++++++++ 5 files changed, 77 insertions(+), 4 deletions(-) diff --git a/db/db_fingerprint.c b/db/db_fingerprint.c index b538658cd2..8ec3e433d1 100644 --- a/db/db_fingerprint.c +++ b/db/db_fingerprint.c @@ -263,6 +263,7 @@ void add_fingerprint(struct sqlclntstate *clnt, sqlite3_stmt *stmt, struct strin } else { t->query_plan_hash = NULL; } + t->alert_once_truncated_col = 1; char fp[FINGERPRINTSZ*2+1]; /* 16 ==> 33 */ util_tohex(fp, (char *)t->fingerprint, FINGERPRINTSZ); @@ -337,6 +338,22 @@ void add_fingerprint(struct sqlclntstate *clnt, sqlite3_stmt *stmt, struct strin assert( strncmp(t->zNormSql,zNormSql,t->nNormSql)==0 ); } + if (clnt->adjusted_column_names && t->alert_once_truncated_col) { + t->alert_once_truncated_col = 0; + char fp[FINGERPRINTSZ * 2 + 1]; /* 16 ==> 33 */ + util_tohex(fp, (char *)fingerprint, FINGERPRINTSZ); + strbuf *msg = strbuf_new(); + strbuf_appendf(msg, "%s: truncated %d columns ", __func__, clnt->num_adjusted_column_name_length); + for (int i = 0; i < clnt->num_adjusted_column_name_length; i++) { + if (i > 0) + strbuf_append(msg, ", "); + strbuf_append(msg, clnt->adjusted_column_names[i]); + } + strbuf_appendf(msg, " for fp %s\n", fp); + logmsg(LOGMSG_WARN, "%s", strbuf_buf(msg)); + strbuf_free(msg); + } + Pthread_mutex_unlock(&gbl_fingerprint_hash_mu); if (logger != NULL) { diff --git a/db/sql.h b/db/sql.h index af040d6f50..0b94697bcc 100644 --- a/db/sql.h +++ b/db/sql.h @@ -88,6 +88,7 @@ struct fingerprint_track { hash_t *query_plan_hash; /* Query plans associated with fingerprint + cost stats */ int alert_once_query_plan; /* Alert only once if there is a better query plan for a query. Init to 1 */ int alert_once_query_plan_max; /* Alert (once) if hit max number of plans for associated query. Init to 1 */ + int alert_once_truncated_col; /* Alert once if we truncated some col in the query. Init to 1 */ }; struct sql_authorizer_state { @@ -950,6 +951,8 @@ struct sqlclntstate { unsigned force_fdb_push_redirect : 1; // this should only be set if can_redirect_fdb is true unsigned force_fdb_push_remote : 1; unsigned return_long_column_names : 1; // if 0 then tunable decides + unsigned num_adjusted_column_name_length; // does not consider fastsql + char **adjusted_column_names; unsigned in_local_cache : 1; char *sqlengine_state_file; @@ -1314,6 +1317,7 @@ int sqlite3_close_serial(sqlite3 **); void reset_clnt(struct sqlclntstate *, int initial); void cleanup_clnt(struct sqlclntstate *); void free_client_info(struct sqlclntstate *); +void free_client_adj_col_names(struct sqlclntstate *); void reset_query_effects(struct sqlclntstate *); int sqlite_to_ondisk(struct schema *s, const void *inp, int len, void *outp, @@ -1482,7 +1486,7 @@ int clear_fingerprints(int *plans_count); void calc_fingerprint(const char *zNormSql, size_t *pnNormSql, unsigned char fingerprint[FINGERPRINTSZ]); void add_fingerprint(struct sqlclntstate *, sqlite3_stmt *, struct string_ref *, const char *, int64_t, int64_t, - int64_t, int64_t, struct reqlogger *, unsigned char *fingerprint_out, int is_lua); + int64_t, int64_t, struct reqlogger *, unsigned char *, int); long long run_sql_return_ll(const char *query, struct errstat *err); long long run_sql_thd_return_ll(const char *query, struct sql_thread *thd, diff --git a/db/sqlinterfaces.c b/db/sqlinterfaces.c index 8cb6cec079..6c6fc9366a 100644 --- a/db/sqlinterfaces.c +++ b/db/sqlinterfaces.c @@ -3919,6 +3919,8 @@ static void sqlite_done(struct sqlthdstate *thd, struct sqlclntstate *clnt, sql_statement_done(thd->sqlthd, thd->logger, clnt, stmt, outrc); + free_client_adj_col_names(clnt); + if (stmt && !((Vdbe *)stmt)->explain && ((Vdbe *)stmt)->nScan > 1 && (BDB_ATTR_GET(thedb->bdb_attr, PLANNER_WARN_ON_DISCREPANCY) == 1 || BDB_ATTR_GET(thedb->bdb_attr, PLANNER_SHOW_SCANSTATS) == 1)) { @@ -5197,6 +5199,18 @@ void free_client_info(struct sqlclntstate *clnt) } } +void free_client_adj_col_names(struct sqlclntstate *clnt) +{ + if (!clnt->adjusted_column_names) + return; + for (int i = 0; i < clnt->num_adjusted_column_name_length; i++) { + free(clnt->adjusted_column_names[i]); + } + free(clnt->adjusted_column_names); + clnt->adjusted_column_names = NULL; + clnt->num_adjusted_column_name_length = 0; +} + void cleanup_clnt(struct sqlclntstate *clnt) { if (clnt->ctrl_sqlengine == SQLENG_INTRANS_STATE) { @@ -5280,6 +5294,8 @@ void cleanup_clnt(struct sqlclntstate *clnt) free(clnt->authdata); clnt->authdata = NULL; + free_client_adj_col_names(clnt); + destroy_hash(clnt->ddl_tables, free_it); destroy_hash(clnt->dml_tables, free_it); clnt->ddl_tables = NULL; @@ -5470,6 +5486,7 @@ void reset_clnt(struct sqlclntstate *clnt, int initial) clnt->force_fdb_push_remote = 0; clnt->typessql = 0; clnt->return_long_column_names = 0; + free_client_adj_col_names(clnt); free(clnt->prev_cost_string); clnt->prev_cost_string = NULL; diff --git a/plugins/newsql/newsql.c b/plugins/newsql/newsql.c index 54d26cd5a1..9799a350db 100644 --- a/plugins/newsql/newsql.c +++ b/plugins/newsql/newsql.c @@ -420,13 +420,18 @@ static int get_col_type(struct sqlclntstate *clnt, sqlite3_stmt *stmt, int col, } #define MAX_COL_NAME_LEN 31 -#define ADJUST_LONG_COL_NAME(clnt_return_long_column_names, appdata, n, l) \ +#define ADJUST_LONG_COL_NAME(clnt_return_long_column_names, appdata, n, l, num_adj, adj) \ do { \ if ((l > MAX_COL_NAME_LEN) && ((!clnt_return_long_column_names && gbl_return_long_column_names == 0) || \ (appdata->protocol_version == NEWSQL_PROTOCOL_COMPAT /* fastsql */))) { \ l = MAX_COL_NAME_LEN + 1; \ char *namebuf = alloca(l); \ n = strncpy0(namebuf, n, l); \ + if (appdata->protocol_version != NEWSQL_PROTOCOL_COMPAT) { /* don't worry about fastsql */ \ + adj = realloc(adj, (num_adj + 1) * sizeof(char *)); \ + adj[num_adj] = strdup(n); \ + ++num_adj; \ + } \ } \ } while (0) @@ -437,12 +442,14 @@ static int newsql_columns(struct sqlclntstate *clnt, sqlite3_stmt *stmt) update_col_info(&appdata->col_info, ncols); CDB2SQLRESPONSE__Column cols[ncols]; CDB2SQLRESPONSE__Column *value[ncols]; + free_client_adj_col_names(clnt); for (int i = 0; i < ncols; ++i) { value[i] = &cols[i]; cdb2__sqlresponse__column__init(&cols[i]); const char *name = sqlite3_column_name(stmt, i); size_t len = strlen(name) + 1; - ADJUST_LONG_COL_NAME(clnt->return_long_column_names, appdata, name, len); + ADJUST_LONG_COL_NAME(clnt->return_long_column_names, appdata, name, len, clnt->num_adjusted_column_name_length, + clnt->adjusted_column_names); cols[i].value.data = (uint8_t *)name; cols[i].value.len = len; cols[i].has_type = 1; @@ -493,12 +500,14 @@ static int newsql_columns_lua(struct sqlclntstate *clnt, } CDB2SQLRESPONSE__Column cols[ncols]; CDB2SQLRESPONSE__Column *value[ncols]; + free_client_adj_col_names(clnt); for (int i = 0; i < ncols; ++i) { value[i] = &cols[i]; cdb2__sqlresponse__column__init(&cols[i]); const char *name = sp_column_name(arg, i); size_t len = strlen(name) + 1; - ADJUST_LONG_COL_NAME(clnt->return_long_column_names, appdata, name, len); + ADJUST_LONG_COL_NAME(clnt->return_long_column_names, appdata, name, len, clnt->num_adjusted_column_name_length, + clnt->adjusted_column_names); cols[i].value.data = (uint8_t *)name; cols[i].value.len = len; cols[i].has_type = 1; diff --git a/tests/column_names_length.test/runit b/tests/column_names_length.test/runit index 6ed830baa2..61da6774da 100755 --- a/tests/column_names_length.test/runit +++ b/tests/column_names_length.test/runit @@ -1,6 +1,32 @@ #!/usr/bin/env bash bash -n "$0" | exit 1 +. ${TESTSROOTDIR}/tools/cluster_utils.sh +. ${TESTSROOTDIR}/tools/runit_common.sh + +# check for log that column was truncated +# should only occur once per fp +function check_logs +{ + logfile="$TESTDIR/logs/$DBNAME.db" + sleep 20 # give time for .db file to flush + # should only get this log message once per fp + if [[ $CLUSTER ]]; then + for node in $CLUSTER ; do + logfile="$TESTDIR/logs/$DBNAME.$node.db" + numOccurrence=$(grep 'add_fingerprint: truncated 1 columns thequickbrownfoxjumpsoverthelaz for fp 42063275be5145b92b705863b8137935' $logfile | wc -l) + if [[ $numOccurrence > 0 ]]; then + break + fi + done + else + numOccurrence=$(grep 'add_fingerprint: truncated 1 columns thequickbrownfoxjumpsoverthelaz for fp 42063275be5145b92b705863b8137935' $logfile | wc -l) + fi + [[ $numOccurrence != 1 ]] && failexit "num occurrence of truncated columns log not equal to 1, got $numOccurrence" + echo "Found truncated columns log" +} ${TESTSROOTDIR}/tools/compare_results.sh -s -d $1 -r sql [ $? -eq 0 ] || exit 1 +check_logs +echo "Success" exit 0