fix: redact encrypted fields from error log#12629
Conversation
| for name, conf in pairs(ctx.var._ctx.consumer.plugins) do | ||
| local plugin = require("apisix.plugins."..name) | ||
| local schema | ||
| if plugin.type == "auth" then | ||
| schema = plugin.consumer_schema | ||
| else | ||
| schema = plugin.schema | ||
| end | ||
| redacted_ctx.var._ctx.consumer.plugins[name] = redact_encrypted(conf, schema) | ||
| local redacted_auth = redact_encrypted(redacted_ctx.var._ctx.consumer.auth_conf, schema) | ||
| redacted_ctx.var._ctx.consumer.auth_conf = redacted_auth | ||
| end |
There was a problem hiding this comment.
this code snippet repeated multiple times, we should put it into a util function to reuse it.
| local redacted_auth = redact_encrypted(redacted_ctx.var._ctx.consumer.auth_conf, schema) | ||
| redacted_ctx.var._ctx.consumer.auth_conf = redacted_auth | ||
| end | ||
| core.log.info("ctx: ", core.json.delay_encode(redacted_ctx, true)) |
There was a problem hiding this comment.
we should avoid to redact the log that will not be printed like json.delay_encode, my suggestion:
local max_delay_encode_items = 16
local delay_tab_idx = 0
local delay_tab_arr = {}
for i = 1, max_delay_encode_items do
delay_tab_arr[i] = setmetatable({data = "", force = false}, {
__tostring = function(self)
if self.redact_func then
self.data = deepcopy(self.data)
self.redact_func(self.data)
end
local res, err = encode(self.data, self.force)
if not res then
ngx.log(ngx.WARN, "failed to encode: ", err,
" force: ", self.force)
end
return res
end
})
end
function _M.delay_encode(data, force, redact_func)
delay_tab_idx = delay_tab_idx+1
if delay_tab_idx > max_delay_encode_items then
delay_tab_idx = 1
end
delay_tab_arr[delay_tab_idx].data = data
delay_tab_arr[delay_tab_idx].force = force
delay_tab_arr[delay_tab_idx].redact_func = redact_func
return delay_tab_arr[delay_tab_idx]
end
only execute redact_func when this line of log be printed actually.
| ## } | ||
| ## After check, it only appears when watch recovers and returns events in bulk. | ||
| cat logs/error.log | grep "}, {" || (echo "failed: Log case 2 unexpected"; exit 1) | ||
| cat logs/error.log | grep "etcd events sent in bulk" || (echo "failed: Log case 2 unexpected"; exit 1) |
There was a problem hiding this comment.
Since the entire res object is no longer logged. We programmatically assert in code and log this specific condition to make this test case pass.
| local dir_res, err = waitdir(self) | ||
| log.info("waitdir key: ", self.key, " prev_index: ", self.prev_index + 1) | ||
| log.info("res: ", json.delay_encode(dir_res, true), ", err: ", err) | ||
|
|
There was a problem hiding this comment.
This log contained sensitive information and was being used to assert if there is a bulk operation. So the entire log is replaced with just the log about whether etcd events were sent in bulk.
| local cjson = require("cjson.safe") | ||
| local json_encode = cjson.encode | ||
| local clear_tab = require("table.clear") | ||
| local table = require("apisix.core.table") |
There was a problem hiding this comment.
we do not need to update this library if we only remove some core.log(....)
| nodes_ver, new_nodes) | ||
| core.log.info("parse route which contain domain: ", | ||
| core.json.delay_encode(route, true)) | ||
| core.json.delay_encode(route, true, function (route) |
There was a problem hiding this comment.
same issue, we can remove this core.log.info
| function _M.merge_consumer_route(route_conf, consumer_conf, consumer_group_conf, api_ctx) | ||
| core.log.info("route conf: ", core.json.delay_encode(route_conf)) | ||
| core.log.info("consumer conf: ", core.json.delay_encode(consumer_conf)) | ||
| core.log.info("consumer conf: ", core.json.delay_encode(consumer_conf, false, |
| end | ||
| core.log.info("check plugin schema, name: ", name, ", configurations: ", | ||
| core.json.delay_encode(plugin_conf, true)) | ||
| core.json.delay_encode(redacted_plugin_conf, true)) |
|
|
||
| function _M.rewrite(conf, ctx) | ||
| core.log.info("plugin access phase, conf: ", core.json.delay_encode(conf)) | ||
| core.log.info("plugin access phase, conf: ", core.json.delay_encode(conf, false)) |
| return core.schema.check(schema, conf) | ||
| cur_schema = schema | ||
| end | ||
| core.log.info("input conf: ", core.json.delay_encode(conf_to_log, false)) |
| end | ||
| core.log.info("consumer: ", core.json.delay_encode(consumer, true)) | ||
|
|
||
| core.log.info("consumer: ", core.json.delay_encode(consumer, true, function (cur_consumer) |
| end | ||
| core.log.info("consumers: ", core.json.delay_encode(consumers)) | ||
| return consumers[key] | ||
| local consumer = consumers[key] |
| resource.set_nodes_ver_and_nodes(route.value.upstream.resource_key, | ||
| nodes_ver, new_nodes) | ||
| -- remove plugin before logging to avoid logging sensitive info | ||
| local route_log = core.table.deepcopy(route) |
There was a problem hiding this comment.
this log is needed for test so only plugins are removed.
|
|
||
|
|
||
| function _M.merge_consumer_route(route_conf, consumer_conf, consumer_group_conf, api_ctx) | ||
| core.log.info("route conf: ", core.json.delay_encode(route_conf)) |
There was a problem hiding this comment.
Does route_conf not print sensitive data?
There was a problem hiding this comment.
Before merging, consumer_conf has the sensitive data. it would have been caught in test if route conf had sensitive data,.
Signed-off-by: Nic <[email protected]> Co-authored-by: Ashish Tiwari <[email protected]>
Currently sensitive encrypted fields are directly logged in plugins. This PR removes from all the places where sensitive information from plugins could be logged.
Checklist