-
Notifications
You must be signed in to change notification settings - Fork 170
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Policy: logging add custom access log options (JSON, Service vars, NGX vars) #1089
Conversation
"name": "apicast.policy.logging", | ||
"configuration": { | ||
"enable_access_logs": false, | ||
"custom_logging": "{\"time_local\": \"{{time_local}}\", \"host\" : \"{{host}}\"}", |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I don't think this would work. It is exploitable by sending values like \"
in headers or the host header. It really needs to be properly serialized.
Hi, I had a chat with Michal today about this policy, there are a couple of issues My proposal for default logging:##Two new ENV variables:
So, if the CUSTOM_ACCESS_LOG is enabled, a new policy like This provides a few good things:
As discussed, this behaviour is not good enough, policies can't be loaded by ENV variable to modify the access_log:This variable will set the access log by default using ENV variable, if not
This has the following strengths:
This has the following weaknesses:
Json render in logs:Michal also commented that the current JSON render is not a valid option, we Example policy configuration:
This has the following weaknesses:
Workaround: Use escape in Liquid log, example:
Please, share your thoughts here, Thanks |
Customers already can enforce policies for all services by using the Account Management API and just add them to the policy chain. All that can be automated without changing APIcast at all. The default logging is just a subset of a feature that would enable configuring any policy by env. I think we should not make a specific case for logging. Either go the full way and have a general solution for all policies or don't do it at all. This is already possible by using a Lua script (environment file). See our APIcast Cloud Hosted: https://github.com/3scale/apicast-cloud-hosted/blob/master/apicast/config/cloud_hosted.lua Regarding the log_format customization, I don't get the drawbacks. Not all the Lua variables are accessible, but some are exposed (like service_id, APIcast/gateway/conf.d/apicast.conf Lines 137 to 148 in 4a71c1d
escape=json and just making the json format like https://stackoverflow.com/questions/25049667/how-to-generate-a-json-log-from-nginx for example.
Regarding the JSON serialization. I think that proper JSON serialization is the only way how to do JSON formatting from Lua. We don't know how big performance drawback it would be yet, so I'd not say it is an issue to serialize them in a loop. Also, we just have to bite the bullet at some point and optimize the liquid library to be JITed and the benefits will be everywhere. To summarize it: To have a default policy somewhere in the global chain, just use the environment file like the APIcast Cloud Hosted. That can be done just by mounting it via a ConfigMap or building it into the image. But for a simpler, per deployment configuration, just allowing to set the custom log format and it's escaping by ENV variables is enough for most cases. I think all the request information that makes sense in logs is available by nginx variables. JSON serialization in Lua has to be done by |
@mikz sorry, I still have two questions regarding this:
Regards. |
A logging policy should use custom format or JSON (by cjson), but in both cases should be escape=none. Not only BuildConfig, but even just mounting the file from ConfigMap works. |
Ok, To summarize:
Custom logging with single log line data:
Custom logging with json log line data:
In case of cjson error, log line will be disabled and nothing will be logged. |
Hi! @eloycoto pointed me this way. I am not very worried about the technical solution. I'm sure you'll come up with a way that gets the job done and is workable for both you and us. However, @mikz you mention that "not all Lua variables are exposed, but some". Is there an exhaustive list somewhere over which variables are available? We have pretty clear requirements regarding what we need to put in the access log. Would it be possible to get service system name and method/metric system name into the access log row with the suggested solution above? |
d3a5e30
to
40f8387
Compare
c19491e
to
bcccc9d
Compare
APIcast/gateway/conf.d/apicast.conf Lines 137 to 153 in 5df6144
usage is the query encoded usage reported to 3scale backend.
|
I didn't know that tool @mikz . It would be good to add those checks to circleCI. |
header in the request, or `{{res.headers.FOO}}` to retrieve FOO header on | ||
response. | ||
- Service information, as `{{service.id}}` and all service propertias as the | ||
`THREESCALE_CONFIG_FILE` parameter provided |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think that this is a bit confusing. It mentions THREESCALE_CONFIG_FILE
, but it also works with THREESCALE_PORTAL_ENDPOINT
.
- Service information, as `{{service.id}}` and all service propertias as the | ||
`THREESCALE_CONFIG_FILE` parameter provided | ||
|
||
## Caveats |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think it's better to put this section below the Examples one. The examples one introduces the attribute fields mentioned here so I think that placing the Examples section before this one gives the reader more context. What do you think?
t/apicast-policy-logging.t
Outdated
} | ||
] | ||
} | ||
--- upstream |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It looks like this is not needed in this test.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Same with the tests below.
t/apicast-policy-logging.t
Outdated
--- no_error_log eval | ||
[qr/\[error/, qr/GET \/ HTTP\/1.1\" 200/] | ||
|
||
=== TEST 6: service uses a custom access log format without a valid condition |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The condition is valid, but it evaluates to false.
t/apicast-policy-logging.t
Outdated
GET / | ||
--- error_code: 200 | ||
--- error_log eval | ||
[ qr/^Status\:\:200/ ] |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We should also check the service ID.
return self:log_dump_line(extended_context) | ||
end | ||
|
||
function _M.enable_extended_access_log() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Shouldn't these functions be local
? I think all of them should except the policy phases.
ngx.var[ngx_var_access_logs_enabled] = self.enable_access_logs_val | ||
if not (self.custom_logging or self.enable_json_logs) then |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Maybe we can define use_default_access_logs
that returns this not ( ... or ... )
.
Then we could write if use_default_access_logs() then return end
.
|
||
return self | ||
end | ||
|
||
function _M:log() | ||
local function get_request_context(context) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Is there a reason to define these headers here instead of reusing ngx_variable
?
I think everything on ngx_variable
should be available. We should define there the response headers, though.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
just because it is easy to provide to users information about the request and response in an easy way.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
But this limits us to the information in the service plus the headers.
I guess it's fine for now but in the future, users might ask for other info that we have in ngx_variable
like it happened for other policies.
spec/policy/logging/logging_spec.lua
Outdated
assert.equals(0, ngx.var.access_logs_enabled) | ||
assert.equals(1, ngx.var.extended_access_logs_enabled) | ||
assert.equals(ngx.var.extended_access_log, expected_json) | ||
assert.spy(logging.log_dump_json).was.called() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why is this needed? The previous assert already verifies that a JSON was generated, no?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
just to make sure that the call to the correct function for future changes.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm not sure about this. Shouldn't we just care about the final result? In that case, we want to verify that the log generated is the JSON we expect. Not sure why we need to assert that a specific private method was called. If in the future we change the internals of this class returning the same result, this test will break.
self.json_object_config = config.json_object_config or {} | ||
|
||
if config.condition then | ||
ngx.log(ngx.DEBUG, 'Enabling extended log with conditions') |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Looks like a good candidate to be extracted into its own function.
69478a3
to
93bc57d
Compare
} | ||
``` | ||
|
||
<<<<<<< HEAD |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
👀
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
🤦♂️
t/apicast-policy-logging.t
Outdated
} | ||
] | ||
} | ||
--- upstream |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is not needed, right?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think it appears on every test starting from this one and it's not needed in any of them.
end | ||
|
||
--- log_dump_json: returns an string with the json output. | ||
function _M:log_dump_json(extended_context) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Shouldn't these functions be local? I mean all of them except log()
.
|
||
|
||
function _M:use_default_access_logs() | ||
if (self.custom_logging or self.enable_json_logs) then |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This can be simplified:
return not (self.custom_logging or self.enable_json_logs)
spec/policy/logging/logging_spec.lua
Outdated
assert.equals(0, ngx.var.access_logs_enabled) | ||
assert.equals(1, ngx.var.extended_access_logs_enabled) | ||
assert.equals(ngx.var.extended_access_log, expected_json) | ||
assert.spy(logging.log_dump_json).was.called() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm not sure about this. Shouldn't we just care about the final result? In that case, we want to verify that the log generated is the JSON we expect. Not sure why we need to assert that a specific private method was called. If in the future we change the internals of this class returning the same result, this test will break.
spec/policy/logging/logging_spec.lua
Outdated
enable_json_logs = true, | ||
json_object_config = { | ||
{ key = "foo", value="{{foo}}", value_type="liquid"}, | ||
{ key = "bar", value="barValue", value_type="liquid"}, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think you forgot about this one.
|
||
return self | ||
end | ||
|
||
function _M:log() | ||
local function get_request_context(context) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
But this limits us to the information in the service plus the headers.
I guess it's fine for now but in the future, users might ask for other info that we have in ngx_variable
like it happened for other policies.
Some users requested different ways to log access log with more metadata, different formats or conditional logging based on multiple request values. This policy address this, two new variables are now set, where allow or disallow to print a custom log message, and another one `extened_access_log` just store all the information to print that. Policy has multiple options, here a few examples: Custom log format ``` { "name": "apicast.policy.logging", "configuration": { "enable_access_logs": false "custom_logging": "\"{{request}}\" to service {{service.id}} and {{service.name}}", } } ``` Only log the entry if status is 200 ``` { "name": "apicast.policy.logging", "configuration": { "enable_access_logs": false "custom_logging": "\"{{request}}\" to service {{service.id}} and {{service.name}}", "condition": { "operations": [ {"op": "==", "match": "{{status}}", "match_type": "liquid", "value": "200"} ], "combine_op": "and" } } } ``` This commit fixed 3scale#1082 and THREESCALE-1234 and THREESCALE-2876 Signed-off-by: Eloy Coto <[email protected]>
Signed-off-by: Eloy Coto <[email protected]>
Signed-off-by: Eloy Coto <[email protected]>
@@ -0,0 +1,172 @@ | |||
# Logging policy | |||
|
|||
This policy has two primary purposes: one is to enable and disable access log |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This policy has two purposes: one is to enable and disable access log
# Logging policy | ||
|
||
This policy has two primary purposes: one is to enable and disable access log | ||
output, and the second one is to be able to create a custom access log format |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
output, and the other is to create a custom access log format
|
||
## Exported variables | ||
|
||
Liquid templating can be used on custom logging, the exported variables are: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Liquid templating can be used on custom logging. The exported variables include:
|
||
## Examples | ||
|
||
### Disable access log: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
### Disabling access logs
} | ||
``` | ||
|
||
### Enable custom access log: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
### Enabling custom access logs
} | ||
``` | ||
|
||
### Enable custom access log with the service ID: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
### Enabling custom access logs with the service ID
} | ||
``` | ||
|
||
### Write access log in JSON format: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
### Configuring access logs in JSON format
} | ||
``` | ||
|
||
### Write a custom access log only for a successful request. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
### Configuring a custom access log only for a successful request
} | ||
``` | ||
|
||
### Write a custom access log where reponse status match 200 or 500. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
### Customizing access logs where reponse status match 200 or 500
## Caveats | ||
|
||
- If `custom_logging` or `enable_json_logs` property is enabled, default access | ||
log will be dissabled. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
log will be disabled.
|
||
- If `custom_logging` or `enable_json_logs` property is enabled, default access | ||
log will be dissabled. | ||
- If `enable_json_logs` is enabled, `custom_logging` field will be omitted |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
If
enable_json_logsis enabled,
custom_logging field will be omitted.
log will be dissabled. | ||
- If `enable_json_logs` is enabled, `custom_logging` field will be omitted | ||
|
||
## Global configuration for all services. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
## Global configuration for all services
|
||
## Global configuration for all services. | ||
|
||
Logging options can be useful in all services, to avoid having issues with logs |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In all services, logging options help to avoid having issues with logs
## Global configuration for all services. | ||
|
||
Logging options can be useful in all services, to avoid having issues with logs | ||
that are not correctly formated in other services, a custom Apicast environment |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
that are not correctly formated in other services, a custom APIcast environment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Some comments and suggestions.
} | ||
``` | ||
|
||
To run Apicast with this specific environment: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
APIcast
``` | ||
|
||
Key concepts of the docker command: | ||
- Current lua file need to be shared to the container `-v $(pwd):/config` |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Current Lua file must be shared to the container
-v $(pwd):/config``
|
||
Key concepts of the docker command: | ||
- Current lua file need to be shared to the container `-v $(pwd):/config` | ||
- `APICAST_ENVIRONMENT` variable need to be set to the lua file that is |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
``APICAST_ENVIRONMENT variable must be set to the Lua file that is
Signed-off-by: Eloy Coto <[email protected]>
output, and the second one is to be able to create a custom access log format | ||
for each service and be able to set conditions to write custom access log. | ||
This policy has two purposes: one is to enable and disable access log output, | ||
and and the other is to create a custom access log format for each service and |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
and the other is to create a custom access log format for each service, as well as to
Remove the first and
.
@@ -20,7 +20,7 @@ response. | |||
|
|||
## Examples | |||
|
|||
### Disable access log: | |||
### Disabling access log: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Remove colon :
from all headings.
### Disabling access logs
@@ -31,7 +31,7 @@ response. | |||
} | |||
``` | |||
|
|||
### Enable custom access log: | |||
### Enabling custom access log: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Remove colon.
### Enabling custom access logs
@@ -43,7 +43,7 @@ response. | |||
} | |||
``` | |||
|
|||
### Enable custom access log with the service ID: | |||
### Enabling custom access log with the service ID: |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
### Enabling custom access logs with service identifier
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Some further refinements.
Signed-off-by: Eloy Coto <[email protected]>
@davidor when can we expect these changes to be available for us users to try out? |
Hi @magnusvage This policy is currently merged and working on master and will be released in the next version 3.7, that release should be out in a couple of months, but some extensive testing needs to be done, and maybe it's delayed, it's a bit early to say a date. Regards |
Some users requested different ways to log the access log with more metadata,
different formats or conditional logging based on multiple request values.
This policy address this, two new variables are now set, where to allow or disallow
to print a custom log message, and another one
extened_access_log
just storeall the information to print that.
The policy has multiple options, here a few examples:
Custom log format
Only log the entry if the status is 200
This pr fixed #1082 and THREESCALE-1234 and THREESCALE-2876