Format MSSQL query logs as executable multi-line SQL with DECLARE parameter headers (including TVP support)#170
Format MSSQL query logs as executable multi-line SQL with DECLARE parameter headers (including TVP support)#170Copilot wants to merge 10 commits into
Conversation
Agent-Logs-Url: https://github.com/durlabhjain/dframework-node/sessions/d09a10ce-2641-4551-b0a7-b3f28054ec3b Co-authored-by: tushar-singh-spraxa <231176744+tushar-singh-spraxa@users.noreply.github.com>
|
@copilot formatSqlQueryForLog in lib/sql.js doesn't handle mssql.Table (TVP) parameters — it dumps them as JSON. Add detection via instanceof mssql.Table, then for TVPs generate executable T-SQL: DECLARE @name [schema].[type] using table.path, followed by INSERT INTO @name (col1, col2) VALUES (val1, val2) using table.columns for names and the existing stringifySqlValue for values — batch up to 100 rows per INSERT with multi-row VALUES. Mix TVP DECLARE+INSERT before scalar DECLARE lines. Add a test in tests/sql-log-format.test.js that creates an mssql.Table, passes it as a parameter, and asserts the output contains the type path and readable row values (not JSON). |
Agent-Logs-Url: https://github.com/durlabhjain/dframework-node/sessions/fb06d526-c59d-401a-bcc5-1c8281924f0e Co-authored-by: tushar-singh-spraxa <231176744+tushar-singh-spraxa@users.noreply.github.com>
Implemented in commit
I also added tests in |
There was a problem hiding this comment.
Pull request overview
This PR improves MSSQL query logging by formatting logged queries as readable, executable multi-line SQL, including generated DECLARE statements for scalar parameters and expanded TVP (mssql.Table) parameters as DECLARE + batched INSERT statements. It updates the slow-query, threshold logger, and error logger paths to use the new formatter and adds targeted tests to validate the emitted log shape.
Changes:
- Added
formatSqlQueryForLogto generate executable SQL log output (scalar params + TVP support with 100-row batching). - Updated MSSQL slow-query, threshold logging (
createQueryLogger), and error logging (runQuerycatch) to emit formatted SQL. - Added
tests/sql-log-format.test.jsto verify formatting behavior and usage across logging call sites.
Reviewed changes
Copilot reviewed 2 out of 2 changed files in this pull request and generated 4 comments.
| File | Description |
|---|---|
| lib/sql.js | Adds SQL log formatting helpers and applies them to query duration, slow-query, and error logging paths. |
| tests/sql-log-format.test.js | Introduces coverage to validate the formatted SQL output (including TVPs and batching) and that all intended log sites use it. |
| if (Buffer.isBuffer(value)) { | ||
| return `0x${value.toString('hex')}`; | ||
| } | ||
| return `'${JSON.stringify(value).replace(/'/g, "''")}'`; | ||
| }; |
| if (value instanceof Date) { | ||
| return `'${dayjs(value).format('YYYY-MM-DD HH:mm:ss.SSS')}'`; | ||
| } |
| const createQueryLogger = function ({ queryLogThreshold, timeoutLogLevel, logger }) { | ||
| return async function ({ query, start, end = Date.now(), parameters }) { | ||
| const queryDurationInMs = (end - start); | ||
| if (queryDurationInMs > queryLogThreshold) { | ||
| logger[timeoutLogLevel]({ | ||
| query: query, | ||
| duration: `${queryDurationInMs}ms`, | ||
| parameters: parameters | ||
| }); | ||
| const formattedQuery = formatSqlQueryForLog({ query, parameters }); | ||
| logger[timeoutLogLevel](`SQL query duration ${queryDurationInMs}ms\n${formattedQuery}`); |
| const formattedQuery = formatSqlQueryForLog({ query, parameters: request.parameters || request.params }); | ||
| loggerToUse.warn(`Query execution exceeded ${maxQueryTime} milliseconds (${executionTime}ms) [${type}]\n${formattedQuery}`); |
Agent-Logs-Url: https://github.com/durlabhjain/dframework-node/sessions/28fa513a-6c28-4e31-9dd0-1fb6d20ff402 Co-authored-by: durlabhjain <18685657+durlabhjain@users.noreply.github.com>
Agent-Logs-Url: https://github.com/durlabhjain/dframework-node/sessions/28fa513a-6c28-4e31-9dd0-1fb6d20ff402 Co-authored-by: durlabhjain <18685657+durlabhjain@users.noreply.github.com>
Agent-Logs-Url: https://github.com/durlabhjain/dframework-node/sessions/28fa513a-6c28-4e31-9dd0-1fb6d20ff402 Co-authored-by: durlabhjain <18685657+durlabhjain@users.noreply.github.com>
| } | ||
| if (Number.isFinite(parameter?.length)) { | ||
| return `${sqlType}(${parameter.length})`; | ||
| } |
| const createQueryLogger = function ({ queryLogThreshold, timeoutLogLevel, logger, dialect = 'mssql' }) { | ||
| return async function ({ query, start, end = Date.now(), parameters }) { | ||
| const queryDurationInMs = (end - start); | ||
| if (queryDurationInMs > queryLogThreshold) { | ||
| logger[timeoutLogLevel]({ | ||
| query: query, | ||
| duration: `${queryDurationInMs}ms`, | ||
| parameters: parameters | ||
| }); | ||
| const formattedQuery = dialect === 'mssql' ? formatSqlQueryForLog({ query, parameters }) : (query || ''); | ||
| logger[timeoutLogLevel]( | ||
| { query, duration: queryDurationInMs, parameters, formattedQuery, dialect }, | ||
| `SQL query duration ${queryDurationInMs}ms\n${formattedQuery}` | ||
| ); |
| const formattedQuery = formatSqlQueryForLog({ query, parameters: request.parameters }); | ||
| loggerToUse.error({ err, type }, `SQL query failed\n${formattedQuery}`); | ||
| return { success: false, err, data: {} }; |
| logSlowQuery({ startTime, query, type, request }) { | ||
| const executionTime = Date.now() - startTime; | ||
| if (executionTime > maxQueryTime) { // 500 milliseconds | ||
| const loggerToUse = request._logger || this.logger; | ||
| loggerToUse.warn({ | ||
| message: `Query execution exceeded ${maxQueryTime} milliseconds`, | ||
| query, | ||
| executionTime: `${executionTime}ms`, | ||
| type, | ||
| parameters: request.parameters || request.params | ||
| }); | ||
| const parameters = request.parameters || request.params; | ||
| const formattedQuery = formatSqlQueryForLog({ query, parameters }); | ||
| loggerToUse.warn( | ||
| { query, type, executionTime, parameters, formattedQuery }, | ||
| `Query execution exceeded ${maxQueryTime} milliseconds (${executionTime}ms) [${type}]\n${formattedQuery}` | ||
| ); |
| parameters: request.parameters || request.params | ||
| }); | ||
| const parameters = request.parameters || request.params; | ||
| const formattedQuery = formatSqlQueryForLog({ query, parameters }); |
Agent-Logs-Url: https://github.com/durlabhjain/dframework-node/sessions/6ce515d1-55d5-4f7a-9226-4aa9431a66b3 Co-authored-by: durlabhjain <18685657+durlabhjain@users.noreply.github.com>
Agent-Logs-Url: https://github.com/durlabhjain/dframework-node/sessions/6ce515d1-55d5-4f7a-9226-4aa9431a66b3 Co-authored-by: durlabhjain <18685657+durlabhjain@users.noreply.github.com>
Agent-Logs-Url: https://github.com/durlabhjain/dframework-node/sessions/6ce515d1-55d5-4f7a-9226-4aa9431a66b3 Co-authored-by: durlabhjain <18685657+durlabhjain@users.noreply.github.com>
Agent-Logs-Url: https://github.com/durlabhjain/dframework-node/sessions/6ce515d1-55d5-4f7a-9226-4aa9431a66b3 Co-authored-by: durlabhjain <18685657+durlabhjain@users.noreply.github.com>
SQL query logs were difficult to read because query text and parameters were emitted as JSON fields with escaped control characters. This updates MSSQL logging to emit readable multi-line SQL and prepend parameter
DECLAREstatements with inferred SQL types and correctly formatted values.Added SQL log formatter for
{ query, parameters }formatSqlQueryForLoginlib/sql.jsDECLARElines:INT,VARCHAR(n),DATETIME2,BIT, etc.)'escaped strings',NULL,1/0for bit, datetime literals, hex for buffers)Added TVP (
mssql.Table) formatting supportinstanceof mssql.TableDECLARE @Param [schema].[Type](fromtable.path)INSERT INTO @Param ([col1], [col2], ...) VALUES (...)table.columnsVALUESApplied formatter at all MSSQL query log sites
logSlowQuery)createQueryLogger)runQuerycatch path)Added focused coverage for log output shape
tests/sql-log-format.test.jsDECLAREgeneration + type/value formatting