You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
* Use contextual logging
All possible direct klog calls are removed.
Instead logr.Logger is loaded from the context
or passed around as an argument.
* Fix log levels
* server: Handle context canceled
* pod_reconciler: Use TRACE log level
Co-authored-by: Abdullah Gharaibeh <[email protected]>
* pod_reconciler: Don't log pod not found err
---------
Co-authored-by: Abdullah Gharaibeh <[email protected]>
We use `logr.Logger` interface for logging everywhere.
6
+
The logger instance is loaded from `context.Context` or passed around as an argument directly.
7
+
This is aligned with contextual logging as explained in [k8s instrumentation logging guidelines](https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/logging.md).
8
+
9
+
In other words, we explicitly don't use `klog` global logging calls.
10
+
Using `klog` log value helpers like `klog.KObj` is just fine.
11
+
6
12
### Change log verbosity
7
-
We use the `k8s.io/klog/v2` package to manage logging.
8
13
9
14
We generally follow the [k8s instrumentation logging guidelines](https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/logging.md), which states "the practical default level is V(2). Developers and QE environments may wish to run at V(3) or V(4)".
10
15
11
-
To configure logging verbosity, specify the `v` flag such as `--v=2`.
16
+
To configure logging verbosity, specify the `v` flag such as `--v=2`.
12
17
13
18
### Add logs
14
19
15
20
The [k8s instrumentation logging guidelines](https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/logging.md) has the following definitions:
16
21
17
-
*`klog.V(0).InfoS` = `klog.InfoS` - Generally useful for this to **always** be visible to a cluster operator
18
-
*`klog.V(1).InfoS` - A reasonable default log level if you don't want verbosity.
19
-
*`klog.V(2).InfoS` - Useful steady state information about the service and important log messages that may correlate to significant changes in the system. This is the recommended default log level for most systems.
20
-
*`klog.V(3).InfoS` - Extended information about changes
21
-
*`klog.V(4).InfoS` - Debug level verbosity
22
-
*`klog.V(5).InfoS` - Trace level verbosity
22
+
-`logger.V(0).Info` = `logger.Info` - Generally useful for this to **always** be visible to a cluster operator
23
+
-`logger.V(1).Info` - A reasonable default log level if you don't want verbosity.
24
+
-`logger.V(2).Info` - Useful steady state information about the service and important log messages that may correlate to significant changes in the system. This is the recommended default log level for most systems.
25
+
-`logger.V(3).Info` - Extended information about changes
26
+
-`logger.V(4).Info` - Debug level verbosity
27
+
-`logger.V(5).Info` - Trace level verbosity
23
28
24
29
We choose to simplify to the following 3 common levels.
30
+
25
31
```
26
32
const(
27
33
DEFAULT=2
@@ -33,34 +39,46 @@ const(
33
39
34
40
The guidelines are written in the context of a k8s controller. Our [ext-proc](../pkg/ext-proc/) does more things such as handling requests and scraping metrics, therefore we adapt the guidelines as follows:
35
41
36
-
1. The server startup process and configuration.
37
-
*`klog.InfoS` Logging at the `V(0)` verbosity level is generally welcome here as this is only logged once at startup, and provides useful info for debugging.
42
+
1. The server startup process and configuration.
43
+
44
+
-`logger.Info` Logging at the `V(0)` verbosity level is generally welcome here as this is only logged once at startup, and provides useful info for debugging.
38
45
39
46
2. Reconciler loops. The reconciler loops watch for CR changes such as the `InferenceModel` CR. And given changes in these CRs significantly affect the behavior of the extension, we recommend using v=1 verbosity level as default, and sparsely use higher verbosity levels.
40
-
41
-
*`klog.V(DEFAULT).InfoS`
42
-
* Default log level in the reconcilers.
43
-
* Information about config (listening on X, watching Y)
44
-
* Errors that repeat frequently that relate to conditions that can be corrected (e.g., inference model not initialized yet)
45
-
* System state changing (adding/removing objects in the data store)
46
-
*`V(VERBOSE)` and above: Use your best judgement.
47
+
48
+
-`logger.V(DEFAULT)`
49
+
- Default log level in the reconcilers.
50
+
- Information about config (listening on X, watching Y)
51
+
- Errors that repeat frequently that relate to conditions that can be corrected (e.g., inference model not initialized yet)
52
+
- System state changing (adding/removing objects in the data store)
53
+
-`logger.V(VERBOSE)` and above: Use your best judgement.
47
54
48
55
3. Inference request handling. These requests are expected to be much higher volume than the control flow in the reconcilers and therefore we should be mindful of log spamming. We recommend using v=2 to log important info about a request, such as the HTTP response code, and higher verbosity levels for less important info.
49
56
50
-
*`klog.V(DEFAULT).InfoS`
51
-
* Logging the status code of an HTTP request
52
-
* Important decision making such as picking the target model, target pod
53
-
*`klog.V(VERBOSE).InfoS`
54
-
* Detailed request scheduling algorithm operations, such as running the filtering logic
55
-
*`V(DEBUG)` and above: Use your best judgement.
57
+
-`logger.V(DEFAULT)`
58
+
- Logging the status code of an HTTP request
59
+
- Important decision making such as picking the target model, target pod
60
+
-`logger.V(VERBOSE)`
61
+
- Detailed request scheduling algorithm operations, such as running the filtering logic
62
+
-`logger.V(DEBUG)` and above: Use your best judgement.
56
63
57
64
4. Metric scraping loops. These loops run at a very high frequency, and logs can be very spammy if not handled properly.
58
-
*`klog.V(TRACE).InfoS`
59
-
* Transient errors/warnings, such as failure to get response from a pod.
60
-
* Important state changes, such as updating a metric.
61
65
62
-
5. Misc
66
+
-`logger.V(TRACE)`
67
+
- Transient errors/warnings, such as failure to get response from a pod.
68
+
- Important state changes, such as updating a metric.
69
+
70
+
5. Misc
63
71
1. Periodic (every 5s) debug loop which prints the current pods and metrics.
64
-
*`klog.WarningS` If the metrics are not fresh enough, which indicates an error occurred during the metric scraping loop.
65
-
*`klog.V(DEBUG).InfoS`
66
-
* This is very important to debug the request scheduling algorithm, and yet not spammy compared to the metric scraping loop logs.
72
+
-`logger.V(DEFAULT).Error` If the metrics are not fresh enough, which indicates an error occurred during the metric scraping loop.
73
+
-`logger.V(DEBUG)`
74
+
- This is very important to debug the request scheduling algorithm, and yet not spammy compared to the metric scraping loop logs.
75
+
76
+
### Passing Logger Around
77
+
78
+
You can pass around a `context.Context` that contains a logger or a `logr.Logger` instance directly.
79
+
You need to make the call which one to use. Passing a `context.Context` is more standard,
80
+
on the other hand you then need to call `log.FromContext` everywhere.
81
+
82
+
As `logger.V` calls are cummulative, i.e. `logger.V(2).V(3)` results in `logger.V(5)`,
83
+
a logger should be passed around with no verbosity level set so that `logger.V(DEFAULT)`
0 commit comments