netcracker/ai-for-dummies
3
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

feat: review Gustavo and Marcos submitted skills

Browse Source
This commit is contained in:
Marcos Silva
2026-09-04 09:07:54 -03:00
parent 6694897ae9
commit 5756dceb5a
38 changed files with 2749 additions and 6 deletions
Download Patch File Download Diff File Expand all files Collapse all files
submitted-skills/Gustavo Ruiz/skills/gfiber-logging/references/anti-patterns.md
+88
View File
@@ -0,0 +1,88 @@
# Anti-patterns
Every example below shipped and passed review in a GFiber service. Check for these first when auditing.
## Printing a pointer instead of the data
```go
logging.LogInfoCtx(ctx, "Valid alarms: %+v", validAlarms) // map[string]*Alarm
logging.LogInfoCtx(ctx, "Alarm results: %+v", alarmResults) // map[string]*AlarmResult
```
Go's `fmt` does not dereference pointers held inside a map or a slice, so what reaches Graylog is a map key and a heap address:
```
Valid alarms: map[7c0e-1:0x7cabe66aa060]
Alarm results: map[7c0e-1:0x7cabe66b4000]
```
Print the identifiers, or a count. A struct or map of values prints fine; a map or slice of pointers does not.
## A verb that is not a verb
```go
logging.LogDebug("... for alarm %s+", alarm) // *Alarm
```
`%s+` is `%s` followed by a literal plus. On a struct with non-string fields `%s` emits error markers:
```
&{7c0e-1 %!s(int=3) %!s(bool=false) 2026-09-02 11:52:06 ...}+
```
Use `%+v`, or a short projection method such as `toShortString()`.
## INFO inside a per-object loop
```go
for _, target := range targets {
...
logging.LogInfo("ONT target %s is not eligible for this ticket: %+v", ontId, target)
}
```
One INFO line per monitoring target, dumping the whole struct, where the logged branch is the normal outcome and not an exception. This scales with ONT count, not with request count. Log the members at DEBUG and one count after the loop.
## A tick that logs whether or not there is work
```go
logging.LogInfoCtx(ctx, "Schedule ticket updates at %v", time.Now())
```
Fired on every scheduler tick. With a five second interval that is roughly 17k INFO lines per day per pod with no work behind them. The tick belongs at DEBUG; the INFO line belongs after the batch, with counts.
## A rejection that returns in silence
A request rejected for capacity, for an unmatched handler or for a malformed body, returning a status code with no log line and no metric. Every identifier in that request is then absent from Graylog, and the request counter and the result counter diverge with nothing to explain the gap.
## A result line that never runs
An early return on a failure path that skips the per-item result loop. The batch is lost and leaves one line with no identifier in it. Populate the results on every exit path, or carry the identifiers on the ERROR.
Watch the status code when fixing this: in `gfiber-policy-executor` filling the results made a fully failed batch fall through the handler condition and answer HTTP 200, and the caller only inspects the status code, so it would have marked the work completed.
## Losing the panic value
```go
logging.LogErrorCtx(ctx, "Unexpected panic: %v", reasonConstant, stackTrace)
```
One verb, two arguments. The recovered value is never printed and the stack trace arrives as `%!(EXTRA string=...)`.
## A line whose whole content is already in the prefix
```go
logging.LogInfoCtx(ctx, "x-request-id=%s", requestId)
```
The runtime prefix already carries `request_id`. The line names no work item, so it costs volume and answers nothing. Replace it with a work-received line that names the ticket or alarm.
## Retry semantics inverted
Logging every retry attempt at WARN while the exhaustion, the moment the work actually moves to a backlog, is silent. The attempt is DEBUG, the exhaustion is ERROR with the identifier.
## Non-context logging
`logging.LogInfo` and friends without `Ctx` drop `request_id` and every business identifier from the MDC, which makes the line impossible to attach to anything.
If the enclosing function has no `ctx` and it is a pure helper, do not thread `ctx` through several signatures only to log. Either move the line to the caller, which has the context, or drop it: a DEBUG line that cannot be correlated is close to useless when two work items are in flight.
submitted-skills/Gustavo Ruiz/skills/gfiber-logging/references/audit.md
+77
View File
@@ -0,0 +1,77 @@
# Auditing a service and the volume gate
## Static audit
Run from the checkout root of any Go service under `sources/project/`. Heuristic, not a linter: it flags short projection methods such as `toShortString()` as dumps, and it does not know about on-demand troubleshooting guards. Read what it prints; do not treat the counts as a gate on their own.
```python
import re, glob
files = [f for f in glob.glob('**/*.go', recursive=True)
if not f.endswith('_test.go') and '/vendor/' not in f]
info = dump = loop = noctx = 0
for path in files:
depth, loops = 0, []
for i, line in enumerate(open(path, errors='ignore'), 1):
stripped = line.strip()
if re.search(r'\bfor .*\{\s*$', stripped):
loops.append(depth)
depth += line.count('{') - line.count('}')
loops = [d for d in loops if d < depth]
if re.search(r'logging\.Log(Info|Debug|Warning|Error|Fatal)\(', line):
noctx += 1
print(f'noCtx {path}:{i}: {stripped[:100]}')
if re.search(r'logging\.LogInfo(Ctx)?\(', line):
info += 1
if '%+v' in line and not re.search(r'%\+v[^"]*"\s*,\s*len\(', line):
dump += 1
print(f'dump {path}:{i}: {stripped[:100]}')
if loops:
loop += 1
print(f'loop {path}:{i}: {stripped[:100]}')
print(f'INFO={info} dump={dump} loop={loop} noCtx={noctx}')
```
To exclude lines already behind an on-demand troubleshooting guard, track the brace depth of the block opened by `IsAlarmTroubleshootingActive(` and skip lines while inside it. In `gfiber-policy-executor` that moved the count from 77 INFO sites to 34 ungated ones, which is the number that matters.
### How to read the output
| Signal | Meaning |
|--------|---------|
| high `dump` against low `INFO` | the few INFO lines the service has are the expensive kind |
| any `loop` | a line scaling with item count rather than request count; the per-item result line is the one legitimate case |
| `noCtx` | lines that cannot be attached to a work item |
## Volume gate
Any change to logging on a high-volume path states its volume impact in the merge request. Measure the same scenario before and after, in the same namespace and window, using the `graylog-search` entry in [scripts/data/index.yaml](../../../scripts/data/index.yaml) with `--scope containers` and a container plus level filter, per [scripts/data/graylog-search.example.md](../../../scripts/data/graylog-search.example.md).
Repeat for INFO, DEBUG, WARN and ERROR, then rerun on the branch build.
| Metric | Before | After | Delta |
|--------|--------|-------|-------|
| INFO messages per run | | | |
| INFO bytes per run | | | |
| DEBUG messages per run | | | |
| WARN and ERROR per run | | | |
| Longest single INFO line, bytes | | | |
Acceptance: INFO message count and INFO bytes must not increase. DEBUG is allowed to grow, since it is off in production.
For SA services use the registered SVT cases from [skills/gfiber-svt-analysis/cases/index.yaml](../../gfiber-svt-analysis/cases/index.yaml). Services without an SVT case need a reference scenario agreed with the reviewer before the gate means anything.
On the same run, confirm that a sample identifier from it is still findable at `LOG_LEVEL: INFO` with the SA alarm template from [queries/graylog/index.yaml](../../../queries/graylog/index.yaml). That is the regression the policy exists to prevent, and it is satisfied by the per-item result line rather than by anything new.
## Merge request checklist
The hard rules in [levels.md](levels.md) double as the review checklist. In addition:
- Every new INFO line matches one of the four INFO cases.
- No new INFO line prints a collection, a struct or a body.
- No new INFO line sits inside a loop over domain objects.
- Every identifier list is capped.
- Every call is the `Ctx` variant.
- WARN and ERROR on failure paths carry the identifiers of the work they lost.
- The summary line is written from a `defer` that survives a panic.
- New metric labels come from a fixed vocabulary, with no identifiers in them.
- `go vet` is clean and no line prints a pointer address or a `%!s` marker.
submitted-skills/Gustavo Ruiz/skills/gfiber-logging/references/cases.md
+73
View File
@@ -0,0 +1,73 @@
# Case catalogue
The cases that come up in GFiber services and the level each one takes. If a case is not here, run the decision list in [levels.md](levels.md) and add a row.
## Work intake and results
| Case | Level | Note |
|------|-------|------|
| Request, batch or message arrived | INFO | counts and the values that identify the scope, such as alarm names, severities, OLT, HUT; no payload and no id list |
| Batch finished | INFO if ok, ERROR otherwise | one summary line with in, out, duration and status, written from a defer registered before any recover so a panic still produces it |
| Result of one work item | INFO | one per item, with its identifier and outcome; this is the line support greps for, and the one line that must never be demoted |
| Payload of the work item | DEBUG | or behind on-demand troubleshooting |
| Decision that ends the item | INFO | only when it is not already visible in that item's result message |
| Intermediate lookup or filter result | DEBUG | log the count at INFO if it matters, the members at DEBUG |
| Anything inside a loop over domain objects | DEBUG | plus one count after the loop |
## Rejections and failures
| Case | Level | Note |
|------|-------|------|
| Input malformed, null or failed validation | WARN | carry the identifiers that survived parsing, and the body size |
| Rejected for capacity or backpressure | WARN | one line per rejected request, never per item |
| No handler or policy matched the work | WARN | carry the identifiers, because no result line will be written |
| Upstream call failed, will be retried | DEBUG | the attempt is not yet a failure |
| Upstream call failed after retries | ERROR | carry the identifiers and the step that stopped |
| Some items succeeded, some failed | ERROR | on the summary line, with the split |
| Panic recovered | ERROR | log the recovered value and the stack, and keep serving |
## Service lifecycle
| Case | Level | Note |
|------|-------|------|
| Started, listeners bound, dependencies resolved | INFO | a handful of lines, once per process |
| Effective configuration | DEBUG | never secrets, tokens or credentials |
| Graceful shutdown | INFO | |
| Cannot start at all | FATAL | the only place FATAL is allowed |
| Database connection established | INFO | once at startup; per query is DEBUG |
## Background work
| Case | Level | Note |
|------|-------|------|
| Scheduled tick that found nothing to do | DEBUG | a tick every few seconds at INFO is one of the cheapest ways to burn retention |
| Scheduled tick that did work | INFO | one line with counts, not one per item |
| Kafka batch consumed | INFO | one summary per batch, same shape as an HTTP batch |
| One Kafka message processed | DEBUG | the per-item result line already covers what support needs |
| Message that cannot be parsed | ERROR | carry the message key and raise a metric; it will never parse, so it is lost work |
| Consumer rebalance or lag | none | leave it to the client library and to metrics |
## Keep out
| Case | Level | Note |
|------|-------|------|
| Health, liveness and readiness probes | none on success | probe traffic is constant; log only a failing probe |
| Every outbound HTTP request and response | DEBUG | rates and durations belong in metrics |
| Upstream returned an empty result | DEBUG | unless it changes the outcome, and then it belongs in the item's result message |
| Third-party library output | set it explicitly | do not let a dependency inherit DEBUG in production |
| Secrets, tokens, passwords | never | at any level |
| ONT serial, account id, hostname | not at INFO | on high-volume paths; fine in a bounded projection or at DEBUG |
If a line has to be INFO and is still too frequent, sample it: log one in N with the count of what was skipped. Demoting it to DEBUG removes it from production entirely, which is usually not the intent.
## Reference implementations
Read these before writing a new one; both were reviewed against this policy.
| What | Where |
|------|-------|
| Per-batch summary line, `key=value`, INFO on ok and ERROR otherwise | `gfiber-policy-executor`, `pkg/faultstatus/stats.go` |
| Per-alarm result line, the one support greps for | `gfiber-policy-executor`, `pkg/policies/executor.go` |
| Ingress line with counts, ids on a DEBUG companion | `gfiber-policy-executor`, `pkg/policies/executor.go` |
| Per-item result line from a defer, covering every failure path | `gfiber-ticketing-proxy`, `pkg/ticket/executor.go` |
| Rejection lines with a fixed reason vocabulary plus a counter | `gfiber-ticketing-proxy`, `pkg/ticket/routes.go` |
submitted-skills/Gustavo Ruiz/skills/gfiber-logging/references/levels.md
+112
View File
@@ -0,0 +1,112 @@
# Levels and the decision list
Canonical source: [How To: What logs belong at INFO, DEBUG, WARN and ERROR in GFiber services](https://bass.netcracker.com/display/GF/How+To%3A++What+logs+belongs+at+INFO%2C+DEBUG%2C+WARN+and+ERROR+in+GFiber+services). This file is the working copy for agents; when the two disagree, the BASS page wins.
## Why there is a ceiling on INFO
Graylog storage is shared across the platform. Every INFO line written on a healthy run is paid for in retention days, so the more a service logs, the shorter the window for grepping an incident that already happened. A service that logs too little is untriageable. The policy is the line between the two.
Three facts that drive every rule below:
- `LOG_LEVEL` is `INFO` in every shipped Helm chart. Treat DEBUG as not present in production.
- Support starts from one identifier, usually an alarm id or a ticket id, and searches Graylog full text. A decision that never printed that identifier cannot be found.
- Batch sizes are not capped upstream. A line inside a loop scales with item count, not with request count.
## Levels
| Level | Use for | Volume on a healthy run |
|-------|---------|-------------------------|
| ERROR | Work was lost and a human must look. Carries the identifiers of the lost work. | rare, each one actionable |
| WARN | An item was dropped or degraded and the service continues. Carries identifiers when no result line will be written. | rare |
| INFO | Work received, work finished, one result per work item. | O(1) per request or batch, plus one line per item |
| DEBUG | Everything else: intermediate collections, per-object detail, payloads, filter internals. | unbounded |
| FATAL | Cannot start and serve. Terminates the process. | startup only |
`mano.netcracker.com/go-logging/v3` exposes `LogDebug`, `LogInfo`, `LogWarning`, `LogError`, `LogFatal` and a `Ctx` variant of each. There is no TRACE.
## Decision list
Walk in order, stop at the first yes.
1. Work was lost and someone has to look at it. Use ERROR.
2. An item was dropped or degraded, and the service keeps going. Use WARN.
3. It is one of these four: work received, work finished, the result of one item, or a decision that ends an item and is not already in that item's result message. Use INFO.
4. It fires more than once per item, or prints a collection, a struct or a body. Use DEBUG.
5. Anything else. Use DEBUG.
When two levels look defensible, take the lower one. A line at DEBUG can be recovered with on-demand troubleshooting or promoted next release. Retention days spent on a line nobody reads cannot.
## WARN or ERROR
The boundary that gets argued about most.
- ERROR means the service could not do what it was asked and no automatic mechanism will fix it. A human has to look.
- WARN means the service did not do something, but that outcome is defined and expected in operation: input was unusable, capacity was full, a business rule dropped the item.
The test: if this fires two hundred times tonight, does someone need to be paged? Yes is ERROR. No is WARN.
Two consequences, both commonly got wrong:
- A call that failed but will be retried automatically is not an ERROR on the attempt. The attempt is DEBUG. It becomes ERROR when the retries are exhausted and the work is actually lost.
- A validation rejection is never an ERROR, however loud it looks. The client sent something unusable and the service behaved correctly. That is WARN.
## FATAL
Startup only, and only when the process cannot serve at all: unreadable configuration, no database, a required dependency that will never appear. `LogFatal` terminates the process, so calling it on a request path turns one bad request into an outage. There is no case for FATAL after the service reports ready.
## Field format
`key=value` pairs, snake_case keys, prefixed by the subject of the line. Quote with `%q` only when the value can be empty or contain spaces.
```go
logging.LogInfoCtx(ctx, "policy batch received: batch_id=%s policy=%q alarms=%d alarm_names=%s",
batchID, request.Policy, len(request.Alarms), distinctAlarmNames(request.Alarms))
```
The runtime already adds a prefix, so do not repeat any of it in the message:
```
[2026-09-02T11:52:06.222] [INFO] [request_id=-] [tenant_id=-] [thread=-] [class=policies:executor.go:68] <your message>
```
### Correlation keys
| Key | Source | Present on |
|-----|--------|-----------|
| `request_id` | MDC, from the cloud-core context propagation middleware | every line, automatically |
| `batch_id` | minted once at ingress, carried in the context | every line handling that batch |
| `alarm_id`, `ticket_id`, `order_id` | the domain object | every line naming a single work item |
| `alarm_ids` | capped list | lines describing a set |
This is not structured logging. The logger emits a text message behind a fixed prefix, so Graylog does not extract these keys into searchable fields. They are found by full text search, which is exactly why identifiers have to appear literally in the message.
## On-demand extended logging
How a service gets full detail in production without raising `LOG_LEVEL` and without paying for it on every healthy run. Every service handling a high-volume work item should implement it. `gfiber-policy-executor` is the reference:
```
PUT /troubleshooting/{entityKey}?minutes=1440
DELETE /troubleshooting/{entityKey}
GET /troubleshooting/{entityKey}
```
In code it is a guard around the verbose block, so the cost when off is one cached lookup:
```go
logging.LogInfoCtx(ctx, "Handling Full Pon Loss for alarm: %+v", alarm.toShortString())
if m.IsAlarmTroubleshootingActive(ctx, alarm) {
logging.LogInfoCtx(ctx, "Alarm (full): %+v", alarm.toFullString())
}
```
The default line carries a bounded projection; the full payload is behind the guard. Setup and supported entity keys: [How to enable troubleshooting logs (gfiber-policy-executor)](https://bass.netcracker.com/pages/viewpage.action?pageId=2466165241).
## Logs are not the only channel
Choosing the right channel is most of the volume problem.
| Channel | Answers | Cannot |
|---------|---------|--------|
| Service log (Graylog) | what happened to this specific id | show trends, and it costs shared retention |
| Prometheus metric | how often, how slow, alerting | carry an identifier; label cardinality forbids it |
| BLM `policy_actions_log` | what we did to this item, on the record | be found from the SA Graylog streams |