From 2bfcb9b0f765c8ecef40cf5138e8363194729c46 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Fri, 23 Jun 2023 15:18:27 +0200 Subject: [PATCH 1/6] refactor: move graphiql GET route registration into `graphiql.js` (#98) * Move graphiql GET route registration into graphiql.js * Remove underscore prefix since function isn't private --- app/graphiql.js | 8 ++++++-- index.js | 4 ++-- lib/GraphQLAdapter.js | 2 +- 3 files changed, 9 insertions(+), 5 deletions(-) diff --git a/app/graphiql.js b/app/graphiql.js index d320482d..23e4a770 100644 --- a/app/graphiql.js +++ b/app/graphiql.js @@ -1,10 +1,14 @@ const path = require('path') +const express = require('express') +const router = express.Router() -module.exports = (req, res, next) => { +router.get('/', (req, res, next) => { if (req.query.query) { // Forward GET requests with query URL parameter to GraphQL server next() } else { res.sendFile(path.join(__dirname, 'graphiql.html')) } -} +}) + +module.exports = router diff --git a/index.js b/index.js index d90aad43..dbdd878d 100644 --- a/index.js +++ b/index.js @@ -3,7 +3,7 @@ const DEBUG = cds.debug('adapters') const GraphQLAdapter = require('./lib/GraphQLAdapter') let services -const _collectServicesAndMountAdapter = (srv, options) => { +const collectServicesAndMountAdapter = (srv, options) => { if (!services) { services = {} cds.on('served', () => { @@ -15,4 +15,4 @@ const _collectServicesAndMountAdapter = (srv, options) => { services[srv.name] = srv } -module.exports = _collectServicesAndMountAdapter +module.exports = collectServicesAndMountAdapter diff --git a/lib/GraphQLAdapter.js b/lib/GraphQLAdapter.js index 6dc63f4e..ed73877a 100644 --- a/lib/GraphQLAdapter.js +++ b/lib/GraphQLAdapter.js @@ -20,7 +20,7 @@ function GraphQLAdapter(options) { next() }) - if (options.graphiql) router.get('/', graphiql) + if (options.graphiql) router.use(graphiql) router.use((req, res) => createHandler({ schema, context: { req, res }, ...options })(req, res)) return router } From 737c617423d3e59a1123aeef951d208d2f60132e Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Fri, 23 Jun 2023 15:20:56 +0200 Subject: [PATCH 2/6] chore: prepare next release (#99) --- CHANGELOG.md | 10 ++++++++++ package.json | 2 +- 2 files changed, 11 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 48769f33..726d0f15 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,16 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). +## Version 0.7.0 - tbd + +### Added + +### Changed + +### Fixed + +### Removed + ## Version 0.6.0 - 2023-06-23 ### Added diff --git a/package.json b/package.json index 95238cef..18495255 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "@cap-js/graphql", - "version": "0.6.0", + "version": "0.7.0", "description": "CDS protocol adapter for GraphQL", "keywords": [ "CAP", From d9b71a54c9b549448db0e887ab4050e9bbbe15f2 Mon Sep 17 00:00:00 2001 From: Johannes Vogel <31311694+johannes-vogel@users.noreply.github.com> Date: Mon, 3 Jul 2023 12:03:31 +0200 Subject: [PATCH 3/6] adapt urls and references to repo name (#100) --- .reuse/dep5 | 6 +++--- README.md | 6 +++--- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/.reuse/dep5 b/.reuse/dep5 index 3b4c2e23..475a7469 100644 --- a/.reuse/dep5 +++ b/.reuse/dep5 @@ -1,7 +1,7 @@ Format: https://www.debian.org/doc/packaging-manuals/copyright-format/1.0/ -Upstream-Name: cds-adapter-graphql +Upstream-Name: graphql Upstream-Contact: The cap team -Source: https://github.com/cap-js/cds-adapter-graphql +Source: https://github.com/cap-js/graphql Disclaimer: The code in this project may include calls to APIs ("API Calls") of SAP or third-party products or services developed outside of this project ("External Products"). @@ -25,6 +25,6 @@ Disclaimer: The code in this project may include calls to APIs ("API Calls") of parties the right to use of access any SAP External Product, through API Calls. Files: * -Copyright: 2022 SAP SE or an SAP affiliate company and cds-adapter-graphql contributors +Copyright: 2022 SAP SE or an SAP affiliate company and cap-js/graphql contributors License: Apache-2.0 diff --git a/README.md b/README.md index 879a78f8..371c4a6b 100644 --- a/README.md +++ b/README.md @@ -1,4 +1,4 @@ -[![REUSE status](https://api.reuse.software/badge/github.com/cap-js/cds-adapter-graphql)](https://api.reuse.software/info/github.com/cap-js/cds-adapter-graphql) +[![REUSE status](https://api.reuse.software/badge/github.com/cap-js/graphql)](https://api.reuse.software/info/github.com/cap-js/graphql) # CDS protocol adapter for GraphQL @@ -32,7 +32,7 @@ _**WARNING:** This package is in an early general availability state. This means ## Support, Feedback, Contributing -This project is open to feature requests/suggestions, bug reports etc. via [GitHub issues](https://github.com/cap-js/cds-adapter-graphql/issues). Contribution and feedback are encouraged and always welcome. For more information about how to contribute, the project structure, as well as additional contribution information, see our [Contribution Guidelines](CONTRIBUTING.md). +This project is open to feature requests/suggestions, bug reports etc. via [GitHub issues](https://github.com/cap-js/graphql/issues). Contribution and feedback are encouraged and always welcome. For more information about how to contribute, the project structure, as well as additional contribution information, see our [Contribution Guidelines](CONTRIBUTING.md). ## Code of Conduct @@ -40,4 +40,4 @@ We as members, contributors, and leaders pledge to make participation in our com ## Licensing -Copyright 2022 SAP SE or an SAP affiliate company and cds-adapter-graphql contributors. Please see our [LICENSE](LICENSE) for copyright and license information. Detailed information including third-party components and their licensing/copyright information is available [via the REUSE tool](https://api.reuse.software/info/github.com/cap-js/cds-adapter-graphql). +Copyright 2022 SAP SE or an SAP affiliate company and cap-js/graphql contributors. Please see our [LICENSE](LICENSE) for copyright and license information. Detailed information including third-party components and their licensing/copyright information is available [via the REUSE tool](https://api.reuse.software/info/github.com/cap-js/graphql). From b46cbcc861b87bc77cfa0389595bb18732596eb2 Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Tue, 4 Jul 2023 14:49:04 +0200 Subject: [PATCH 4/6] feat: improved query logging (#85) * Don't log 'GET undefined' when missing query * WIP improved request logger * Add operationName and variables to object * Extract request logger to own module * Add changelog entry * Reformat changelog entry * Remove outdated changelog entry * Remove padding after query * Prettier format * Log `operationName` and `variables` from URL query parameter * Parse variables JSON string if taken from `req.query` * Add typeof object short-circuiting before Object.keys * Sanitize arguments and their values in production * Reorder changelog entries * Rename requestLogger to queryLogger * Add query logging tests * Rename `logger.test.js` to `logger-dev.test.js` * Add test for log sanetization in production * Prettier format * Fix logger module path * Fix truncation of nested variables * Fix typo * Move object formatting to only affect query info object * Add and improve comments * Log variables object as '***' in production * Fix typo * Use mocked instead of dummy auth * Add dev logging tests to prod to ensure no unwanted values are sanitized * Add tests that ensures literal values are not sanitized in dev * Use `{color:false,depth:null}` options for formatting everywhere * Prettier format * Fix property name typo `color`->`colors` and helper function call * Move changelog entries from added to changed section --------- Co-authored-by: Johannes Vogel <31311694+johannes-vogel@users.noreply.github.com> --- CHANGELOG.md | 6 + lib/GraphQLAdapter.js | 13 +- lib/logger.js | 47 ++++ test/resources/bookshop-graphql/package.json | 15 ++ test/tests/logger-dev.test.js | 253 ++++++++++++++++++ test/tests/logger-prod.test.js | 264 +++++++++++++++++++ 6 files changed, 590 insertions(+), 8 deletions(-) create mode 100644 lib/logger.js create mode 100644 test/resources/bookshop-graphql/package.json create mode 100644 test/tests/logger-dev.test.js create mode 100644 test/tests/logger-prod.test.js diff --git a/CHANGELOG.md b/CHANGELOG.md index 726d0f15..238343dc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,6 +11,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Changed +- Improved query logging: + + Don't log queries that are `undefined` + + Log `operationName` + + Log `variables` when not in production + + Sanitize arguments and their values in queries when in production + ### Fixed ### Removed diff --git a/lib/GraphQLAdapter.js b/lib/GraphQLAdapter.js index ed73877a..497344b0 100644 --- a/lib/GraphQLAdapter.js +++ b/lib/GraphQLAdapter.js @@ -1,10 +1,8 @@ -const cds = require('@sap/cds') -const LOG = cds.log('graphql') const express = require('express') -const { createHandler } = require('graphql-http/lib/use/express') const { generateSchema4 } = require('./schema') +const queryLogger = require('./logger') const graphiql = require('../app/graphiql') -const { decodeURIComponent } = cds.utils +const { createHandler } = require('graphql-http/lib/use/express') function GraphQLAdapter(options) { const router = express.Router() @@ -15,13 +13,12 @@ function GraphQLAdapter(options) { router .use(express.json()) //> required by logger below - .use((req, _, next) => { - LOG.info(req.method, req.body?.query || decodeURIComponent(req.query.query)) - next() - }) + .use(queryLogger) if (options.graphiql) router.use(graphiql) + router.use((req, res) => createHandler({ schema, context: { req, res }, ...options })(req, res)) + return router } diff --git a/lib/logger.js b/lib/logger.js new file mode 100644 index 00000000..ee865feb --- /dev/null +++ b/lib/logger.js @@ -0,0 +1,47 @@ +const cds = require('@sap/cds') +const { decodeURIComponent } = cds.utils +const LOG = cds.log('graphql') +const util = require('util') + +const IS_PRODUCTION = process.env.NODE_ENV === 'production' + +const queryLogger = (req, _, next) => { + let query = req.body?.query || (req.query.query && decodeURIComponent(req.query.query)) + // Only log requests that contain a query + if (!query) { + next() + return + } + query = query.trim() + + const operationName = req.body?.operationName || req.query?.operationName + + let variables = req.body?.variables || req.query?.variables + if (typeof variables === 'string') { + try { + // variables is a JSON string if taken from req.query.variables + variables = JSON.parse(variables) + } catch (e) { + // Ignore parsing errors, handled by GraphQL server + } + } + if (IS_PRODUCTION && variables) variables = '***' + + // Only add properties to object that aren't undefined + const queryInfo = Object.fromEntries(Object.entries({ operationName, variables }).filter(([, v]) => v)) + // Only format queryInfo if it contains properties + const formattedQueryInfo = + Object.keys(queryInfo).length > 0 ? util.formatWithOptions({ colors: false, depth: null }, queryInfo) : undefined + + // If query is multiline string, add newline padding to front + let formattedQuery = query.includes('\n') ? `\n${query}` : query + // Sanitize all values between parentheses + if (IS_PRODUCTION) formattedQuery = formattedQuery.replace(/\([\s\S]*?\)/g, '( *** )') + + // Don't log undefined values + LOG.info(...[req.method, formattedQueryInfo, formattedQuery].filter(e => e)) + + next() +} + +module.exports = queryLogger diff --git a/test/resources/bookshop-graphql/package.json b/test/resources/bookshop-graphql/package.json new file mode 100644 index 00000000..4b36951d --- /dev/null +++ b/test/resources/bookshop-graphql/package.json @@ -0,0 +1,15 @@ +{ + "cds": { + "requires": { + "db": { + "kind": "sqlite", + "credentials": { + "database": ":memory:" + } + }, + "auth": { + "kind": "mocked" + } + } + } +} diff --git a/test/tests/logger-dev.test.js b/test/tests/logger-dev.test.js new file mode 100644 index 00000000..b686e40e --- /dev/null +++ b/test/tests/logger-dev.test.js @@ -0,0 +1,253 @@ +describe('graphql - query logging in development', () => { + const cds = require('@sap/cds/lib') + const path = require('path') + const { gql } = require('../util') + const util = require('util') + + const { axios, GET, POST, data } = cds.test(path.join(__dirname, '../resources/bookshop-graphql')) + // Prevent axios from throwing errors for non 2xx status codes + axios.defaults.validateStatus = false + data.autoReset(true) + + const _format = e => util.formatWithOptions({ colors: false, depth: null }, ...(Array.isArray(e) ? e : [e])) + + let _log + + beforeEach(() => { + _log = jest.spyOn(console, 'info') + }) + + afterEach(() => { + jest.clearAllMocks() + }) + + describe('POST requests', () => { + test('Do not log requests with undefined queries', async () => { + await POST('/graphql') + expect(_log.mock.calls.length).toEqual(0) + }) + + test('Log should contain HTTP method', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await POST('/graphql', { query }) + expect(_format(_log.mock.calls[0])).toContain('POST') + }) + + test('Log should not contain operationName if none was provided', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await POST('/graphql', { query }) + expect(_format(_log.mock.calls[0])).not.toContain('operationName') + }) + + test('Log should not contain variables if none were provided', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await POST('/graphql', { query }) + expect(_format(_log.mock.calls[0])).not.toContain('variables') + }) + + test('Log should contain operationName and its value', async () => { + const operationName = 'ListBooks' + const query = gql` + query ListAuthors { + AdminService { + Authors { + nodes { + name + } + } + } + } + query ${operationName} { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await POST('/graphql', { operationName, query }) + expect(_format(_log.mock.calls[0])).toContain(`operationName: '${operationName}'`) + }) + + test('Log should contain literal values', async () => { + const secretTitle = 'secret' + const query = gql` + mutation { + AdminService { + Books { + create (input: { title: "${secretTitle}" }) { + title + } + } + } + } + ` + await POST('/graphql', { query }) + expect(_format(_log.mock.calls[0])).toContain(secretTitle) + }) + + test('Log should contain variables and their values', async () => { + const query = gql` + query ($filter: [AdminService_Books_filter]) { + AdminService { + Books(filter: $filter) { + nodes { + title + } + } + } + } + ` + const variables = { filter: { ID: { ge: 250 } } } + await POST('/graphql', { query, variables }) + expect(_format(_log.mock.calls[0])).toContain(`variables: ${_format(variables)}`) + }) + }) + + describe('GET requests', () => { + test('Do not log requests with undefined queries', async () => { + await GET('/graphql') + expect(_log.mock.calls.length).toEqual(0) + }) + + test('Log should contain HTTP method', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?query=${query}`) + expect(_format(_log.mock.calls[0])).toContain('GET') + }) + + test('Log should not contain operationName if none was provided', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?query=${query}`) + expect(_format(_log.mock.calls[0])).not.toContain('operationName') + }) + + test('Log should not contain variables if none were provided', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?query=${query}`) + expect(_format(_log.mock.calls[0])).not.toContain('variables') + }) + + test('Log should contain operationName and its value', async () => { + const operationName = 'ListBooks' + const query = gql` + query ListAuthors { + AdminService { + Authors { + nodes { + name + } + } + } + } + query ${operationName} { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?operationName=${operationName}&query=${query}`) + expect(_format(_log.mock.calls[0])).toContain(`operationName: '${operationName}'`) + }) + + test('Log should contain literal values', async () => { + const secretTitle = 'secret' + const query = gql` + query { + AdminService { + Books(filter: { title: { ne: "${secretTitle}"}}) { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?query=${query}`) + expect(_format(_log.mock.calls[0])).toContain(secretTitle) + }) + + test('Log should contain variables and their values', async () => { + const query = gql` + query ($filter: [AdminService_Books_filter]) { + AdminService { + Books(filter: $filter) { + nodes { + title + } + } + } + } + ` + const variables = { filter: { ID: { ge: 250 } } } + await GET(`/graphql?query=${query}&variables=${JSON.stringify(variables)}`) + expect(_format(_log.mock.calls[0])).toContain(`variables: ${_format(variables)}`) + }) + }) +}) diff --git a/test/tests/logger-prod.test.js b/test/tests/logger-prod.test.js new file mode 100644 index 00000000..668bec09 --- /dev/null +++ b/test/tests/logger-prod.test.js @@ -0,0 +1,264 @@ +describe('graphql - query logging with sanitization in production', () => { + process.env.NODE_ENV = 'production' + const cds = require('@sap/cds/lib') + const path = require('path') + const { gql } = require('../util') + const util = require('util') + + const PROJECT_PATH = path.join(__dirname, '../resources/bookshop-graphql') + + const { axios, GET, POST, data } = cds.test(PROJECT_PATH) + // Prevent axios from throwing errors for non 2xx status codes + axios.defaults.validateStatus = false + data.autoReset(true) + + const _format = e => util.formatWithOptions({ colors: false, depth: null }, ...(Array.isArray(e) ? e : [e])) + + let _log + + beforeAll(async () => { + await cds.deploy(path.join(PROJECT_PATH, 'srv')) + }) + + beforeEach(() => { + _log = jest.spyOn(console, 'info') + }) + + afterEach(() => { + jest.clearAllMocks() + }) + + describe('POST requests', () => { + test('Do not log requests with undefined queries', async () => { + await POST('/graphql') + expect(_log.mock.calls.length).toEqual(0) + }) + + test('Log should contain HTTP method', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await POST('/graphql', { query }) + expect(_format(_log.mock.calls[0])).toContain('POST') + }) + + test('Log should not contain operationName if none was provided', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await POST('/graphql', { query }) + expect(_format(_log.mock.calls[0])).not.toContain('operationName') + }) + + test('Log should not contain variables if none were provided', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await POST('/graphql', { query }) + expect(_format(_log.mock.calls[0])).not.toContain('variables') + }) + + test('Log should contain operationName and its value', async () => { + const operationName = 'ListBooks' + const query = gql` + query ListAuthors { + AdminService { + Authors { + nodes { + name + } + } + } + } + query ${operationName} { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await POST('/graphql', { operationName, query }) + expect(_format(_log.mock.calls[0])).toContain(`operationName: '${operationName}'`) + }) + + test('Log should not contain literal values', async () => { + const secretTitle = 'secret' + const query = gql` + mutation { + AdminService { + Books { + create (input: { title: "${secretTitle}" }) { + title + } + } + } + } + ` + await POST('/graphql', { query }) + expect(_format(_log.mock.calls[0])).not.toContain(secretTitle) + }) + + test('Log should not contain variables or their values', async () => { + const secretTitle = 'secret' + const query = gql` + mutation ($input: [AdminService_Books_C]!) { + AdminService { + Books { + create(input: $input) { + title + } + } + } + } + ` + const variables = { input: { title: secretTitle } } + await POST('/graphql', { query, variables }) + expect(_format(_log.mock.calls[0])).not.toContain('$input') + expect(_format(_log.mock.calls[0])).not.toContain(secretTitle) + }) + }) + + describe('GET requests', () => { + test('Do not log requests with undefined queries', async () => { + await GET('/graphql') + expect(_log.mock.calls.length).toEqual(0) + }) + + test('Log should contain HTTP method', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?query=${query}`) + expect(_format(_log.mock.calls[0])).toContain('GET') + }) + + test('Log should not contain operationName if none was provided', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?query=${query}`) + expect(_format(_log.mock.calls[0])).not.toContain('operationName') + }) + + test('Log should not contain variables if none were provided', async () => { + const query = gql` + { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?query=${query}`) + expect(_format(_log.mock.calls[0])).not.toContain('variables') + }) + + test('Log should contain operationName and its value', async () => { + const operationName = 'ListBooks' + const query = gql` + query ListAuthors { + AdminService { + Authors { + nodes { + name + } + } + } + } + query ${operationName} { + AdminService { + Books { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?operationName=${operationName}&query=${query}`) + expect(_format(_log.mock.calls[0])).toContain(`operationName: '${operationName}'`) + }) + + test('Log should not contain literal values', async () => { + const secretTitle = 'secret' + const query = gql` + query { + AdminService { + Books(filter: { title: { ne: "${secretTitle}"}}) { + nodes { + title + } + } + } + } + ` + await GET(`/graphql?query=${query}`) + expect(_format(_log.mock.calls[0])).not.toContain(secretTitle) + }) + + test('Log should not contain variables or their values', async () => { + const secretTitle = 'secret' + const query = gql` + query ($filter: [AdminService_Books_filter]) { + AdminService { + Books(filter: $filter) { + nodes { + title + } + } + } + } + ` + const variables = { filter: { title: { ne: secretTitle } } } + await GET(`/graphql?query=${query}&variables=${JSON.stringify(variables)}`) + expect(_format(_log.mock.calls[0])).not.toContain('$filter') + expect(_format(_log.mock.calls[0])).not.toContain(secretTitle) + }) + }) +}) From 76ba892709cf7aceac1d9fa2b87f829d2d5e0e9b Mon Sep 17 00:00:00 2001 From: Marcel Schwarz Date: Wed, 5 Jul 2023 10:01:45 +0200 Subject: [PATCH 5/6] fix: GraphiQL Explorer Plugin CDN URL (#101) * Fix GraphiQL explorer plugin CDN URL * Add changelog entry --- CHANGELOG.md | 2 ++ app/graphiql.html | 2 +- 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 238343dc..6d9cc10f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -19,6 +19,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed +- Changed GraphiQL Explorer Plugin CDN URL due to upstream renaming + ### Removed ## Version 0.6.0 - 2023-06-23 diff --git a/app/graphiql.html b/app/graphiql.html index c862ce56..60c55124 100644 --- a/app/graphiql.html +++ b/app/graphiql.html @@ -25,7 +25,7 @@ - +