In 06-04 you built observability's first pillar. AlpinaShop now has a dashboard, uptime checks from four continents and three alerts that reach Marta's phone. It is an enormous leap from waiting for a customer's email.
But look at what happens when that alert really fires. It is eleven at night and Marta's phone shows: "5xx error rate above 2 % for 5 minutes". Marta opens the dashboard. Confirmed: 4.3 % of requests are failing, the p95 latency has gone from 400 ms to 3.2 seconds, and it started about twenty minutes ago. And now what?
The metric has told her that something is wrong. It does not tell her what. It does not tell her which exception is being raised, or which customers it is happening to, or whether it is in the catalogue or the basket, or whether the culprit is the application, the database or a call to an external API. For that you need the other two pillars.
This lesson builds them. And it ends with the complete journey through that incident, from the alert to the exact line of code, because that correlation — jumping from the alert to the metric, from the metric to the log and from the log to the trace — is the reason observability exists.
Contents
- The structured log entry
- Where logs come from automatically
- Emitting logs properly from the Flask application
- The Logs Explorer and its query language
- Queries that solve real AlpinaShop incidents
- Buckets, retention, views and scopes
- Sinks: exporting to BigQuery, Cloud Storage and Pub/Sub
- Exclusion filters: not paying for noise
- Log-based metrics
- Cloud Trace: what distributed tracing is
- Instrumenting Flask with OpenTelemetry
- Reading a waterfall and finding the slow query
- Sampling and the cost of traces
- Cloud Profiler: continuous profiling
- The correlation that ties it all together: an incident end to end
- Cost by volume and the three decisions that control it
- The structured log entry
A log is not a line of text. In Cloud Logging, a log entry is an object with fields, and understanding those fields is what turns logs from a rubbish tip into a queryable database.
| Field | What it contains | Why it matters |
|---|---|---|
timestamp |
When it happened | Ordering and correlating |
resource |
Which resource emitted it, with its labels | Filtering by service, cluster, instance |
severity |
DEBUG, INFO, WARNING, ERROR, CRITICAL |
Filtering by severity |
logName |
Name of the log | Separating access, application, audit |
textPayload |
Plain text | What a print emits |
jsonPayload |
JSON object with your fields | What makes real querying possible |
labels |
Your own key-value labels | Business dimensions |
httpRequest |
Method, URL, code, latency, IP | Access analytics |
trace |
The trace identifier | The key to correlation (section 15) |
spanId |
The span identifier within the trace | Precision in the correlation |
insertId |
Unique identifier of the entry | Deduplication |
operation |
Groups entries of a long operation | Following a process step by step |
The difference between textPayload and jsonPayload is the difference between being able to investigate and not being able to.
Without structure:
It is readable for a human and opaque to a machine. To answer "how many orders failed because of a gateway timeout in the last hour, and for what amount?" you have to parse text with regular expressions, and it only takes somebody changing the message for everything to break.
With structure:
{
"severity": "ERROR",
"jsonPayload": {
"mensaje": "Error processing order",
"id_pedido": "8842",
"id_cliente_hash": "a3f9c1...",
"causa": "timeout_pasarela",
"importe_eur": 249.90,
"duracion_ms": 5012,
"reintento": 2
},
"labels": {"componente": "checkout", "version": "a3f9c1b"},
"trace": "projects/alpinashop-prod/traces/4bf92f3577b34da6a3ce929d0e0e4736"
}Now that question is a filter. And the second-to-last line makes something even more powerful possible: jumping straight to the complete trace of that request, with everything that happened before and after. We will come back to it.
- Where logs come from automatically
As with metrics, there is good news: a good part of the logs are already being collected without you having done anything.
| Source | Log | What it contains | Enabled by default? |
|---|---|---|---|
| Load balancer | requests |
Every request: URL, code, latency, IP, country | No: it has to be enabled |
| Cloud SQL | postgres.log / mysql-error.log |
Errors, slow queries | Partially |
| GKE | Containers' stdout / stderr |
What the application writes | Yes |
| GKE | events |
Kubernetes events | Yes |
| Cloud Run / Functions | stdout / stderr + requests |
Application and access | Yes |
| VPC Flow Logs | vpc_flows |
Network connections, bytes | No: they have to be enabled |
| Cloud Armor | Inside the load balancer's log | Rules applied and blocks | With the LB log |
| Audit logs | activity |
Who did what in the API | Yes (admin activity) |
| Audit logs | data_access |
Who read what data | No: you enable it and it costs |
Two cells deserve attention.
The load balancer's logs are not enabled by default, and they are among the most valuable there are: they contain every request to the shop with its latency, its code, its country of origin and the CDN cache result. To enable them:
gcloud compute backend-services update bs-catalogo-web \
--global \
--enable-logging \
--logging-sample-rate=1.0 \
--project=alpinashop-prodThe --logging-sample-rate=1.0 records 100 % of requests. That is right while the volume is moderate; with millions of daily requests you drop to 0.1 or 0.05 and accept losing detail in exchange for cost. Start at 1.0 and adjust when you see the bill.
VPC Flow Logs record network connections and are indispensable for diagnosing connectivity problems and for investigating security incidents. Their volume is high, so they are enabled with sampling:
gcloud compute networks subnets update sn-web-euw1 \
--region=europe-west1 \
--enable-flow-logs \
--logging-aggregation-interval=interval-5-sec \
--logging-flow-sampling=0.5 \
--project=alpinashop-prodAnd the audit logs deserve a mention with a forward reference: the admin activity ones — who created, modified or deleted a resource — are always on and are free. The data access ones — who read what — have to be enabled, they generate an enormous volume and they are charged for. The audit policy at the organization level, with its compliance implications, is the subject of 07-07; here it is enough to know they exist and that they answer the question "who deleted that resource?".
- Emitting logs properly from the Flask application
This is where AlpinaShop's team has the most room for improvement. The catalogue does this today:
It works in the sense that the text ends up in Cloud Logging — on GKE, everything that goes to stdout is collected. But it produces entries with textPayload, all with INFO severity even when they are errors, with no queryable field and no trace identifier.
The right way, with the client library:
# catalogo/registro.py
import logging
import google.cloud.logging
from google.cloud.logging.handlers import StructuredLogHandler
from google.cloud.logging_v2.handlers import setup_logging
# On GKE and Cloud Run, StructuredLogHandler writes JSON to stdout
# and the agent picks it up. No extra API calls: it is the most efficient way.
handler = StructuredLogHandler()
setup_logging(handler)
log = logging.getLogger("catalogo")
log.setLevel(logging.INFO)And how it is used, with the data as fields and not as text:
# catalogo/pedidos.py
from catalogo.registro import log
def process_order(order):
# The 'json_fields' dictionary becomes jsonPayload
log.info("Order received", extra={"json_fields": {
"id_pedido": order.id,
"importe_eur": float(order.amount),
"num_lineas": len(order.lines),
"canal": order.channel,
}})
try:
result = charge(order)
except GatewayTimeout as e:
# log.exception automatically adds the full traceback
log.exception("Timeout on the payment gateway", extra={"json_fields": {
"id_pedido": order.id,
"importe_eur": float(order.amount),
"causa": "timeout_pasarela",
"duracion_ms": e.duration_ms,
}})
raiseThe five rules of a useful log, which are worth more than any library:
| Rule | Bad | Good |
|---|---|---|
| Data goes in fields, not in the message | f"order {id} failed" |
"Order failed" + {"id_pedido": id} |
| The severity must be right | Everything INFO |
ERROR for errors, WARNING for warnings |
| Never personal data | Email, name, card | Hash of the customer identifier |
| Enough context to act on | "Error" |
Which operation, on what, why it failed |
| No noise | One log per loop iteration | One log per operation, with the summary |
The third rule is not negotiable and goes beyond good taste. Logs are retained, exported to BigQuery, read by several people and survive for months. An email address or a card number written into a log is a personal-data leak with GDPR implications, consistent with everything seen in 04-07 about DLP. If you need to identify a customer in the logs, use a stable hash that allows correlation without identification.
On severity, a practical criterion that avoids endless arguments:
| Level | When | Does it raise an alert? |
|---|---|---|
DEBUG |
Development detail | Never in production |
INFO |
Normal business events | No |
WARNING |
Something odd that recovered on its own | No, but it is watched |
ERROR |
The operation failed for the user | Yes |
CRITICAL |
The service cannot continue | Yes, urgently |
The distinction between WARNING and ERROR is the one most often got wrong: a retry that then works is WARNING — the user never noticed; an exhausted retry that returns an error to the customer is ERROR.
- The Logs Explorer and its query language
The Logs Explorer is the query interface, and its language is simple but has details worth knowing.
The basic operators:
resource.type="k8s_container" # exact equality severity>=ERROR # severity comparison jsonPayload.importe_eur>100 # numeric comparison jsonPayload.mensaje:"pasarela" # ':' is CONTAINS, not equality jsonPayload.causa=~"timeout.*" # regular expression timestamp>="2026-08-05T20:00:00Z" # time range resource.type="k8s_container" AND severity=ERROR # combination NOT jsonPayload.ruta="/salud" # negation
| Operator | Meaning | Important note |
|---|---|---|
= |
Exact equality | Case sensitive |
: |
Contains | Substring search |
=~ / !~ |
Matches / does not match a regex | Slower |
>=, <=, >, < |
Comparison | Numbers, dates and severities |
AND, OR, NOT |
Logical | Use brackets to group |
Leading - |
Excludes | -severity=INFO |
Three performance tips that change the experience a great deal, because a badly written query over weeks of logs takes minutes:
- Always narrow the time first. It is by far the most efficient filter.
- Filter by
resource.typeearly. It cuts the search space down at a stroke. - Avoid global free-text search if you can filter on a specific field: searching in
jsonPayload.causais orders of magnitude faster than searching for the word across all the content.
From the command line, for scripts and for automation:
gcloud logging read \
'resource.type="k8s_container"
AND resource.labels.namespace_name="tienda"
AND severity>=ERROR
AND timestamp>="2026-08-05T20:00:00Z"' \
--limit=50 --format=json --project=alpinashop-prod
- Queries that solve real AlpinaShop incidents
The theory is short; what is useful are the patterns. These five queries cover most real investigations.
Query 1 — The 500 errors since the last deployment. The first question in any incident:
resource.type="k8s_container" resource.labels.namespace_name="tienda" severity>=ERROR timestamp>="2026-08-05T20:15:00Z"
And refined, to see whether the problem belongs to a specific version — which links up with $COMMIT_SHA from 06-01:
resource.type="k8s_container" resource.labels.namespace_name="tienda" severity>=ERROR labels.version="a3f9c1b"
Query 2 — Isolate the request of a customer who has complained. A customer writes saying their purchase failed at 20:34:
resource.type="k8s_container" jsonPayload.id_cliente_hash="a3f9c1e8b2..." timestamp>="2026-08-05T20:30:00Z" timestamp<="2026-08-05T20:40:00Z"
Here you see the value of the personal-data rule: the hash lets you find the customer without ever having written their email into a log. Customer support turns the email into a hash with the same function, and the investigation works just the same.
Query 3 — Who deleted a resource. The audit logs, which answer the most uncomfortable question:
logName="projects/alpinashop-prod/logs/cloudaudit.googleapis.com%2Factivity" protoPayload.methodName="v1.compute.firewalls.delete" timestamp>="2026-08-01T00:00:00Z"
The answer includes protoPayload.authenticationInfo.principalEmail — who — and protoPayload.resourceName — what. It is the query that settles in thirty seconds arguments that would otherwise last an afternoon.
Query 4 — Slow load balancer requests with their origin. Over the access log from section 2:
And the same log answers a cost question from 03-03, the CDN hit ratio:
resource.type="http_load_balancer" jsonPayload.cacheId!="" jsonPayload.statusDetails="response_from_cache"
Query 5 — Errors from the image function. Closing the circle with 06-03:
resource.type="cloud_run_revision" resource.labels.service_name="procesar-imagen-producto" severity>=ERROR
And the one that would have caught the infinite loop from that lesson's exercise, counting invocations per hour:
resource.type="cloud_run_revision" resource.labels.service_name="procesar-imagen-producto" jsonPayload.message:"Processed successfully"
- Buckets, retention, views and scopes
Logs are stored in log buckets, which have nothing to do with Cloud Storage ones.
Every project has two by default:
| Bucket | Contents | Default retention | Configurable? |
|---|---|---|---|
_Required |
Admin activity audit logs | 400 days | No, and it is free |
_Default |
Everything else | 30 days | Yes |
And you can create your own buckets, which is what is needed when different kinds of log require different treatment:
# A bucket with long retention for anything payment-related
gcloud logging buckets create logs-pagos \
--location=europe-west1 \
--retention-days=2555 \
--description="Transaction logs - 7-year retention required by regulation" \
--project=alpinashop-prod
# And another with short retention for development debug logs
gcloud logging buckets create logs-debug \
--location=europe-west1 \
--retention-days=7 \
--project=alpinashop-devChoosing the retention has two dimensions worth separating:
| Need | Retention | Where |
|---|---|---|
| Diagnosing an incident | 7-30 days | Log bucket |
| Analysing trends | Months | Exported to BigQuery |
| Regulatory compliance | Years | Exported to Cloud Storage |
Keeping years of logs in a log bucket is the most expensive way of keeping them. For long retention, the right pattern is exporting to Cloud Storage with a cold storage class, which is the subject of the next section.
Log views let you grant access to a subset of a bucket. It is the piece that solves a real permissions problem: giving Lucía access to the application logs without exposing the audit logs or the payment ones to her.
gcloud logging views create vista-catalogo \
--bucket=_Default --location=global \
--log-filter='resource.type="k8s_container" AND resource.labels.namespace_name="tienda"' \
--project=alpinashop-prod
gcloud logging views add-iam-policy-binding vista-catalogo \
--bucket=_Default --location=global \
--member='group:[email protected]' \
--role=roles/logging.viewAccessor \
--project=alpinashop-prodWithout views, log read permission is all or nothing, and "all" includes the audit logs. With views, access is narrowed, consistent with the least privilege from 03-04.
- Sinks: exporting to BigQuery, Cloud Storage and Pub/Sub
A sink is a rule that says: "entries matching this filter, send them to this destination as well". It is the mechanism that connects logs with the rest of the platform.
flowchart LR
A[Cloud Logging<br/>Log Router] --> B{Sink<br/>filters}
B -->|access logs| C[BigQuery<br/>SQL analysis]
B -->|everything, compressed| D[Cloud Storage<br/>cheap archive]
B -->|critical errors| E[Pub/Sub<br/>automatic reaction]
B -->|default| F[_Default bucket<br/>30 days]
To BigQuery, to analyse. AlpinaShop's case: analysing the load balancer's access log with SQL, joining it with the data in alpinashop_analitica:
gcloud logging sinks create sumidero-acceso-bq \
bigquery.googleapis.com/projects/alpinashop-datos/datasets/logs_acceso \
--log-filter='resource.type="http_load_balancer"' \
--use-partitioned-tables \
--project=alpinashop-prod
# The sink creates its own service account, which has to be granted permission
SA=$(gcloud logging sinks describe sumidero-acceso-bq \
--project=alpinashop-prod --format='value(writerIdentity)')
gcloud projects add-iam-policy-binding alpinashop-datos \
--member="$SA" --role=roles/bigquery.dataEditorThe writerIdentity step is forgotten constantly: the sink is created, it seems to work, and nothing arrives at the destination because the permission is missing. It is the first place to look if a sink is not delivering.
The --use-partitioned-tables matters for cost: it partitions by date, so a query over one day does not scan months, applying what was learned in 04-01.
And then you can do analyses that would be impossible with the explorer:
-- Top 20 slowest URLs of the last week, with volume
SELECT
httpRequest.requestUrl AS url,
COUNT(*) AS peticiones,
ROUND(APPROX_QUANTILES(
CAST(REGEXP_EXTRACT(httpRequest.latency, r'([\d.]+)') AS FLOAT64), 100)[OFFSET(95)], 3
) AS latencia_p95_s,
COUNTIF(httpRequest.status >= 500) AS errores_5xx
FROM `alpinashop-datos.logs_acceso.requests_*`
WHERE _TABLE_SUFFIX BETWEEN FORMAT_DATE('%Y%m%d', DATE_SUB(CURRENT_DATE(), INTERVAL 7 DAY))
AND FORMAT_DATE('%Y%m%d', CURRENT_DATE())
GROUP BY url
HAVING peticiones > 100
ORDER BY latencia_p95_s DESC
LIMIT 20;To Cloud Storage, to archive cheaply. The destination for long retention:
gcloud logging sinks create sumidero-archivo-gcs \
storage.googleapis.com/alpinashop-logs-archivo \
--log-filter='logName:"cloudaudit.googleapis.com" OR jsonPayload.componente="checkout"' \
--project=alpinashop-prodWith a lifecycle rule on the bucket (02-02) dropping to Nearline at 30 days, Coldline at 90 and Archive at a year, seven years of payment logs cost a tiny fraction of what they would cost in a log bucket.
To Pub/Sub, to react. The most interesting sink conceptually, because it closes the circle with 06-03:
gcloud logging sinks create sumidero-seguridad-pubsub \
pubsub.googleapis.com/projects/alpinashop-prod/topics/eventos-seguridad \
--log-filter='protoPayload.methodName=~"compute.firewalls.(insert|patch|delete)"
OR protoPayload.methodName="SetIamPolicy"' \
--project=alpinashop-prodEvery time somebody touches a firewall rule or an IAM policy, a message arrives on the topic, and a Cloud Function from 06-03 can post it to the security channel in Slack. From a log to an automatic reaction, with no human involvement.
| Destination | Latency | Cost | What for |
|---|---|---|---|
| BigQuery | Seconds | Storage + queries | Analysing with SQL |
| Cloud Storage | Minutes (in batches) | The cheapest | Archive, compliance |
| Pub/Sub | Seconds | Per message | Reacting in real time |
| Another log bucket | Immediate | Ingestion | Different retention per type |
| Another project | Seconds | Ingestion | Centralised aggregation (07-07) |
- Exclusion filters: not paying for noise
A sink copies; an exclusion filter discards. And it is the most direct lever on the logging bill.
The reasoning is simple: some logs are generated in enormous volume and add nothing to diagnosis. At AlpinaShop the main ones are the health checks — hc-catalogo hits /salud every few seconds from several probes, generating tens of thousands of identical entries a day — and the requests for static assets served by the CDN.
# Exclude the health checks from the load balancer's log
gcloud logging sinks update _Default \
--add-exclusion=name=excluir-health-checks,\
filter='resource.type="http_load_balancer" AND httpRequest.requestUrl:"/salud"' \
--project=alpinashop-prod
# Exclude 95 % of successful static requests, keeping a sample
gcloud logging sinks update _Default \
--add-exclusion=name=excluir-estaticos,\
filter='resource.type="http_load_balancer"
AND httpRequest.status=200
AND httpRequest.requestUrl=~"\.(css|js|png|jpg|webp|woff2)$"',\
percent=95 \
--project=alpinashop-prodThe percent=95 parameter is very useful and little known: it excludes a random sample instead of everything. Keeping 5 % lets you still see trends and detect problems with the static assets, while paying a twentieth.
| Candidate for exclusion | Typical volume | Risk of excluding it |
|---|---|---|
| Health checks | Very high | None: the metrics already cover them |
| Static assets with code 200 | High | Low, if you keep a sample |
DEBUG in production |
High | None: it should not be on |
Logs from alpinashop-dev |
Medium | Low: short retention is enough |
| Errors of any kind | Low | Never exclude them |
| Audit logs | Medium | Never: regulatory obligation |
And the indispensable warning: an excluded entry is not stored anywhere and cannot be recovered. If you exclude something that later turns out to be necessary for investigating an incident, there is no way back. Review every exclusion with the question: could I need this during an investigation? When in doubt, sample rather than exclude outright.
- Log-based metrics
Here the link with 06-04 is closed. A log-based metric turns entries matching a filter into a Cloud Monitoring metric, without touching the application's code.
It is the fastest technique for instrumenting something that is already being logged.
A counter metric, for counting occurrences:
gcloud logging metrics create pagos_fallidos \
--description="Payments failing because of a gateway timeout" \
--log-filter='resource.type="k8s_container"
AND jsonPayload.causa="timeout_pasarela"' \
--project=alpinashop-prodWith labels so it can be broken down, defined from a file:
# metrica-pagos-fallidos.yaml
name: pagos_fallidos
description: Payments failing because of a gateway timeout
filter: |
resource.type="k8s_container"
AND jsonPayload.causa="timeout_pasarela"
labelExtractors:
canal: EXTRACT(jsonPayload.canal)
version: EXTRACT(labels.version)
metricDescriptor:
metricKind: DELTA
valueType: INT64
labels:
- key: canal
- key: versionNotice the version label: it lets you answer "did these failures start with yesterday's deployment?" immediately, correlating with the SHA from 06-01. And it respects the cardinality rule from 06-04: canal has three values, version a few dozen. Never extract id_pedido as a label.
A distribution metric, for numeric values:
name: importe_pedidos
description: Distribution of the amount of completed orders
filter: |
resource.type="k8s_container"
AND jsonPayload.evento="pedido_completado"
valueExtractor: EXTRACT(jsonPayload.importe_eur)
metricDescriptor:
metricKind: DELTA
valueType: DISTRIBUTIONThat lets you plot the p50 and p95 of the average order value, a pure business figure obtained without writing a line of specific instrumentation.
| Approach | Advantage | Drawback |
|---|---|---|
| Log-based metric | No code changes, immediate | Depends on the log format; if it changes, it breaks |
| Custom metric (06-04) | Explicit, robust | Requires code and a deployment |
The practical recommendation: start with log-based metrics to validate quickly what is worth measuring, and promote to custom metrics the ones that turn out to matter. And keep the risk in mind: if somebody renames a jsonPayload field, the metric silently stops counting and the associated alert stops firing. A change to a log's format is a change with consequences, and it deserves a mention in code review.
- Cloud Trace: what distributed tracing is
The metrics say the p95 is 3.2 seconds. The logs say there were errors. Neither says where those 3.2 seconds went.
That is the gap distributed tracing fills, and the need for it grows with the number of pieces. A request to AlpinaShop's catalogue today crosses: the load balancer, Cloud Armor, the CDN, the GKE pod, a query to Cloud SQL, a Firestore read for the basket and perhaps a call to the Vision API. If it takes three seconds, whose fault is it?
Two concepts:
- A trace represents one complete request through the whole system, identified by a
trace_id. - A span represents an operation within that trace, with a start, an end and a parent span. Spans form a tree.
flowchart TD
A["GET /catalogo/piolet-01<br/>3,240 ms — root span"] --> B["product_detail<br/>3,200 ms"]
A --> C["render_template<br/>40 ms"]
B --> D["SELECT productos<br/>40 ms"]
B --> E["SELECT stock_por_talla<br/>3,020 ms — 93% of the total"]
B --> F["recommendations<br/>20 ms"]
Just looking at the diagram, the answer jumps out: SELECT stock_por_talla takes 3,020 of the 3,240 ms. No metric and no log would have pointed at that with such clarity.
Context propagation is what allows spans from different services to form a single trace. The service that starts the request generates a trace_id and sends it in a header; each service that receives it reads it, creates its spans as children and propagates it onwards.
| Header | Origin | Format | Status in 2026 |
|---|---|---|---|
traceparent |
W3C standard | 00-{trace_id}-{span_id}-{flags} |
The recommended one |
X-Cloud-Trace-Context |
{trace_id}/{span_id};o={flags} |
Native to GCP, still very common | |
b3 / X-B3-TraceId |
Zipkin | Several | Legacy |
The GCP load balancer adds X-Cloud-Trace-Context automatically to every incoming request, so AlpinaShop already has trace identifiers circulating without having done anything. What is missing is for the application to use them.
- Instrumenting Flask with OpenTelemetry
OpenTelemetry is the industry standard for instrumentation — metrics, traces and logs — and it is vendor-independent. Instrumenting with OpenTelemetry and exporting to Cloud Trace means that if AlpinaShop changes destination tomorrow, you change the exporter and not the instrumentation.
# requirements.txt opentelemetry-api==1.* opentelemetry-sdk==1.* opentelemetry-instrumentation-flask==0.* opentelemetry-instrumentation-requests==0.* opentelemetry-instrumentation-sqlalchemy==0.* opentelemetry-exporter-gcp-trace==1.* opentelemetry-propagator-gcp==1.*
# catalogo/trazas.py
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.sdk.trace.sampling import TraceIdRatioBased, ParentBased
from opentelemetry.exporter.cloud_trace import CloudTraceSpanExporter
from opentelemetry.instrumentation.flask import FlaskInstrumentor
from opentelemetry.instrumentation.requests import RequestsInstrumentor
from opentelemetry.instrumentation.sqlalchemy import SQLAlchemyInstrumentor
from opentelemetry.propagate import set_global_textmap
from opentelemetry.propagators.cloud_trace_propagator import CloudTraceFormatPropagator
import os
def configure_tracing(app, engine):
"""Instruments the Flask application and exports to Cloud Trace."""
# Sampling: ParentBased respects the decision of the service that originated
# the trace; if it is the first one, it samples at the given ratio.
ratio = float(os.environ.get("TRACE_SAMPLE_RATE", "0.1"))
provider = TracerProvider(sampler=ParentBased(TraceIdRatioBased(ratio)))
# BatchSpanProcessor groups the spans and sends them in batches:
# essential so as not to add latency to every request.
provider.add_span_processor(BatchSpanProcessor(CloudTraceSpanExporter()))
trace.set_tracer_provider(provider)
# Use Google's format so it agrees with the load balancer
set_global_textmap(CloudTraceFormatPropagator())
# Automatic instrumentation: spans without touching the business code
FlaskInstrumentor().instrument_app(app) # one span per request
RequestsInstrumentor().instrument() # one span per outgoing HTTP call
SQLAlchemyInstrumentor().instrument(engine=engine) # one span per SQL queryWith those last three lines you already have useful traces without modifying a single business function. For your own detail, manual spans:
# catalogo/producto.py
from opentelemetry import trace
tracer = trace.get_tracer(__name__)
def product_detail(sku):
with tracer.start_as_current_span("product_detail") as span:
span.set_attribute("sku", sku) # LOW-cardinality attributes
with tracer.start_as_current_span("query_stock"):
stock = get_stock_by_size(sku)
span.set_attribute("tallas_disponibles", len(stock))
with tracer.start_as_current_span("recommendations"):
recos = get_recommendations(sku) # table from 05-07
return render(sku, stock, recos)And the piece that changes everything: including the trace_id in the logs. It is what will make the journey in section 15 possible:
# catalogo/registro.py
from opentelemetry import trace
def trace_fields() -> dict:
"""Returns the fields that link a log with its trace."""
span = trace.get_current_span()
ctx = span.get_span_context()
if not ctx.is_valid:
return {}
project = os.environ["GOOGLE_CLOUD_PROJECT"]
return {
"logging.googleapis.com/trace": f"projects/{project}/traces/{ctx.trace_id:032x}",
"logging.googleapis.com/spanId": f"{ctx.span_id:016x}",
"logging.googleapis.com/trace_sampled": ctx.trace_flags.sampled,
}
def log_info(message: str, **fields):
log.info(message, extra={"json_fields": {**fields, **trace_fields()}})Those special keys logging.googleapis.com/trace and .../spanId are not just any fields: Cloud Logging recognises them and fills in the entry's trace and spanId fields. And with that, the console shows a direct link from each log to its trace, and from each trace to its logs.
- Reading a waterfall and finding the slow query
With the instrumentation in place, this is how you read a slow trace from AlpinaShop's catalogue:
| Span | Duration | % of total | Observation |
|---|---|---|---|
GET /catalogo/piolet-01 |
3,240 ms | 100 % | The root span |
├─ product_detail |
3,200 ms | 99 % | Almost all the time |
│ ├─ SELECT productos |
40 ms | 1 % | Normal |
│ ├─ SELECT stock_por_talla |
3,020 ms | 93 % | The culprit |
│ └─ recommendations |
20 ms | 1 % | The precomputed table from 05-07 |
└─ render_template |
40 ms | 1 % | Normal |
The diagnosis is immediate, and the three things to look at in any waterfall are always the same:
- Which span takes the largest percentage? Here,
stock_por_tallawith 93 %. Optimising anything else is a waste of time. - Are there uncovered gaps? An interval inside the parent span that no child accounts for is usually waiting time: locks, connection pool contention or uninstrumented code.
- Are there repeated spans? Fifty identical consecutive
SELECTspans are the unmistakable signature of the N+1 problem: one query per element of a list, instead of one query for all of them.
With the SQL attribute added by the SQLAlchemy instrumentation, the trace includes the query:
SELECT s.talla, s.unidades
FROM stock s
WHERE s.sku = 'piolet-01'
AND s.almacen IN (SELECT id FROM almacenes WHERE activo = true);And from there the investigation is a database one: EXPLAIN ANALYZE on that query, review indexes, look at Cloud SQL's slow query logs. The trace does not fix the problem; it locates it in thirty seconds instead of three hours, and that is exactly what is asked of it.
One pattern deserves a separate mention: if that same query takes 40 ms in a test environment and 3,020 ms in production, the problem is probably not the query but contention — the connection pool exhausted, with the request waiting for one to be released. There the Cloud SQL connections metric from 06-04 and the trace reinforce each other: the trace says where the waiting happens, the metric says why.
- Sampling and the cost of traces
Tracing 100 % of requests has two costs: span ingestion, which is billed, and performance in the application, which although small is not zero. That is why you sample.
| Strategy | How it works | When |
|---|---|---|
| Fixed ratio | A percentage of the traces | The usual: 1-10 % in production |
| Parent-based | Respects the first service's decision | Always, combined with the above |
| Always on | 100 % | Development and one-off debugging |
| Tail-based | Decides at the end, based on the result | Ideal, requires your own collector |
The ParentBased(TraceIdRatioBased(0.1)) combination from section 11 is the right default, and it deserves an explanation: TraceIdRatioBased(0.1) samples 10 % of new traces, and ParentBased guarantees that if a trace was sampled at the start, every service that receives it samples it too. Without ParentBased, each service would decide on its own and you would get incomplete traces with holes, which are worse than having no traces.
Tail-based sampling is what everybody would want — keeping 100 % of the slow or failing traces and 1 % of the normal ones — because the interesting traces are precisely the anomalous ones. It requires an OpenTelemetry collector that holds the spans until the end of the request in order to decide. For AlpinaShop today it is excessive complexity; it is worth knowing it exists for when the system grows.
Recommendation per environment:
| Environment | Ratio | Reason |
|---|---|---|
alpinashop-dev |
100 % | Low volume, you want to see everything |
alpinashop-prod normally |
5-10 % | Enough to detect patterns |
| During an incident | Raise it temporarily | That is why it is an environment variable |
Making the ratio an environment variable (TRACE_SAMPLE_RATE) is deliberate: it lets you raise it to 100 % during an investigation without redeploying code, and lower it afterwards.
- Cloud Profiler: continuous profiling
A trace says a function takes 800 ms. It does not say what it does during those 800 ms. That is what profiling is for.
Cloud Profiler continuously collects CPU and memory samples from the application in production, with very low overhead — of the order of a small percentage — and shows a flame graph of where time and memory are going.
# catalogo/app.py, at the start of the boot sequence
import googlecloudprofiler
try:
googlecloudprofiler.start(
service="catalogo-web",
service_version=os.environ["VERSION_IMAGEN"], # the SHA from 06-01
verbose=0,
)
except (ValueError, NotImplementedError) as e:
log.warning("Could not start the profiler: %s", e)The three cases where Profiler solves what no other pillar can:
| Case | Symptom | What it reveals |
|---|---|---|
| Memory leak | The pod restarts every few hours from OOM | Which structure grows without being released |
| High CPU with no clear cause | The metric says 85 %, the trace points at nothing | Which specific function is consuming |
| Optimising what matters | You want to improve performance | Where the time really goes |
The third deserves a warning: intuition about where the bottleneck is is usually wrong. It is common to spend two days optimising a function that consumes 3 % of the total time while 60 % goes on a JSON serialisation nobody looked at. Profiler avoids that waste with data instead of guesswork.
And comparison by version is where it shines: with service_version set to the image SHA, you can compare two versions' profiles and see exactly what introduced a performance regression.
- The correlation that ties it all together: an incident end to end
This section is the whole module's reason for being. We return to the moment the lesson started with.
flowchart TD
A[23:14 ALERT<br/>5xx rate > 2%] --> B[23:15 DASHBOARD<br/>4.3% errors, p95 3.2s]
B --> C[23:17 LOGS<br/>severity=ERROR<br/>last 30 min]
C --> D[23:19 A pattern:<br/>causa=timeout_consulta<br/>on /catalogo]
D --> E[23:21 TRACE<br/>from the log's trace]
E --> F[23:23 WATERFALL<br/>SELECT stock_por_talla<br/>3,020 ms]
F --> G[23:25 CAUSE<br/>index dropped<br/>in the 22:50 migration]
G --> H[23:31 MITIGATION<br/>rollback with 06-01]
23:14 — The alert. It reaches Marta's phone. It carries the documentation field with the first four steps, so she does not start from scratch.
23:15 — The dashboard. Confirmed: 4.3 % errors, p95 of 3.2 s against the usual 400 ms, and the MIG's CPU low. That last fact is informative in itself: if there were a traffic spike, the CPU would be high. It is not, so the problem is not one of capacity.
23:17 — The logs. First query, the one from section 5:
resource.type="k8s_container" resource.labels.namespace_name="tienda" severity>=ERROR timestamp>="2026-08-05T23:00:00Z"
About 800 entries come up. Marta looks at one:
{
"severity": "ERROR",
"jsonPayload": {
"mensaje": "Timeout querying stock",
"sku": "piolet-01",
"causa": "timeout_consulta",
"duracion_ms": 5001,
"id_cliente_hash": "a3f9c1..."
},
"labels": {"componente": "catalogo", "version": "a3f9c1b"},
"trace": "projects/alpinashop-prod/traces/4bf92f3577b34da6a3ce929d0e0e4736"
}23:19 — The pattern. She refines the query grouping by cause and discovers that 94 % of the errors have causa="timeout_consulta" and all of them are on catalogue routes. It is not a general failure: it is one specific operation.
23:21 — The trace. And here is the jump that justifies all the instrumentation from section 11: in the console, that log entry's trace field is a link. One click and the complete trace of that exact request appears, the one belonging to the specific customer who suffered the error.
23:23 — The waterfall. The trace is the one from section 12: SELECT stock_por_talla consumes 3,020 of 3,240 ms. With the SQL query visible in the span's attributes.
23:25 — The cause. Marta runs query 3 over the audit logs and over the Cloud Build history: at 22:50 a database migration was applied that, among other things, dropped and recreated an auxiliary table without recreating the index on (sku, almacen). Without that index, the query goes from an indexed lookup to a full scan.
23:31 — The mitigation. The index is recreated, and in parallel the version rollback is prepared with the pipeline from 06-01. Latency returns to normal in three minutes.
Seventeen minutes from the alert to the root cause identified. Without this journey, the same investigation would have been: find out from a customer the next morning, look at the website, fail to reproduce the problem because night traffic is different, trawl through unstructured logs searching for text, suspect three wrong things and, with luck, hit on it by the end of the day.
| Piece | What exactly it contributed |
|---|---|
| Alert (06-04) | Finding out in 5 minutes, not the next morning |
| Dashboard (06-04) | Confirming the scope and ruling out a lack of capacity |
| Structured logs | Grouping 800 errors into one pattern, not reading 800 lines |
jsonPayload |
Grouping by causa without parsing text |
The trace field |
The jump from the log to the trace: one click |
| Trace | Locating 93 % of the time in one query |
| The span's SQL attribute | The exact query, without guessing |
| Audit logs | Correlating with the 22:50 change |
The version label |
Knowing which version introduced the problem |
| Pipeline (06-01) | Rollback in minutes, with a known image |
The lesson to take away: no piece works on its own. An alert without logs only produces anxiety. Logs without structure are a rubbish tip. Traces without correlated logs force you to search blindly for which one to look at among millions. The value is in the links between the pieces, and the specific link that makes the whole journey possible is one line of code: including the trace_id in every log entry.
- Cost by volume and the three decisions that control it
The model is simple: you pay per GB ingested, with a free monthly volume. Retention within the default period is not billed separately; extending it is. And always check the current prices in the official documentation.
| Component | You pay for | Free tier |
|---|---|---|
| Log ingestion | GB ingested | A generous monthly volume |
| Extended retention | GB × month beyond the default period | — |
| Admin audit logs | Nothing | Always free |
| Trace ingestion | Spans ingested | A monthly volume |
| Profiler | Nothing | Included |
| Sinks to Cloud Storage or Pub/Sub | The destination, not the routing | — |
The three decisions that control the bill, in order of impact:
Decision 1: what gets ingested. By far the most important, because it affects everything else. The exclusion filters from section 8 on health checks and static assets typically cut between 40 % and 70 % of the volume of a typical website, without losing any diagnostic value. And in the application: DEBUG off in production and no logs inside loops.
Decision 2: how long it is kept and where. Thirty days in the log bucket for diagnosis, and whatever has to be kept longer, exported. A sink to Cloud Storage with a lifecycle to Coldline and Archive makes seven years of payment logs cost orders of magnitude less than extending the bucket's retention.
Decision 3: how much is sampled. It applies to the load balancer log (--logging-sample-rate), to VPC Flow Logs (--logging-flow-sampling) and to traces (TRACE_SAMPLE_RATE). At high volume, 10 % is usually enough to detect patterns, because statistics do not need the complete census.
And the mistake to avoid above all others: excluding error logs to save money. They are a minimal percentage of the volume and 100 % of the value during an incident. The savings are in the repetitive noise, never in the exceptional.
A final perspective for calibration: for AlpinaShop, complete observability — logs, traces, metrics, alerts — comes to a small fraction of the cost of the infrastructure it observes. Compared with the seventeen minutes from section 15 versus a whole day of blind investigation, and with the orders saved by detecting an incident in five minutes instead of twelve hours, it is one of the platform's most profitable investments.
Common Mistakes and Tips
Using print instead of structured logging. The text does end up in Cloud Logging, yes, but with no severity, no queryable fields and no trace. It is the difference between being able to investigate and not being able to.
Putting the data in the message instead of in fields. f"order {id} failed" forces you to parse text. "Order failed" plus {"id_pedido": id} lets you filter and aggregate.
Writing personal data into the logs. Emails, names, cards, addresses. Logs are retained, exported and read by a lot of people. Use stable hashes.
Everything at INFO severity. It makes filtering by severity impossible and renders alerts based on severity>=ERROR useless. And a retry that works is WARNING, not ERROR.
Forgetting the writerIdentity when creating a sink. The sink is created without error and delivers nothing. It is the first place to look when a destination is empty.
Excluding logs without thinking twice. What is excluded is not stored anywhere and is not recoverable. When in doubt, sample with percent rather than excluding outright. And never exclude errors or audit logs.
Keeping years of logs in a log bucket. It is the most expensive way. For long retention, a sink to Cloud Storage with a lifecycle.
High-cardinality labels on log-based metrics. The same mistake as in 06-04: EXTRACT(jsonPayload.id_pedido) creates one time series per order. Extract dimensions with dozens of values, not thousands.
Tracing without ParentBased in the sampler. Each service decides on its own and you get incomplete traces with holes, which confuse more than they help.
Not including the trace_id in the logs. It is one line of code and it is the piece that turns three independent tools into a diagnostic system. Without it, jumping from the log to the trace is impossible.
Optimising by intuition instead of by profile. Two days improving a function that consumes 3 % of the time. Measure first with Profiler.
A final tip: the instrumentation is tested before the incident. Cause an error on purpose in alpinashop-dev, find its log, jump to its trace and check that the complete journey works. Discovering at eleven at night that the trace field is empty is discovering it at the worst possible moment.
Exercises
Exercise 1: redesign a module's logging
This is the real code of a function in AlpinaShop's catalogue:
def process_return(order_id, customer_email, reason):
print("Processing return for order " + str(order_id))
try:
order = get_order(order_id)
if order.status != "entregado":
print("Order not delivered, it cannot be returned: " + str(order_id))
return False
refund = compute_refund(order)
execute_refund(order, refund)
print("Return OK for " + customer_email + ", amount " + str(refund))
return True
except Exception as e:
print("Error: " + str(e))
return FalseRewrite it with structured logging fixing every problem you spot, justify each change, and write the Logs Explorer query that answers "how many returns were rejected for an incorrect status this week, and for what average amount?".
Exercise 2: design the retention and export strategy
AlpinaShop generates approximately: 80 GB/month of load balancer logs, 15 GB/month of application logs, 30 GB/month of VPC Flow Logs, 2 GB/month of admin audit logs and 5 GB/month of Cloud SQL logs. Requirements: payment transaction logs must be kept for 7 years by regulation; the team needs 30 days for diagnosis; Lucía wants to analyse the access log with SQL over the last 12 months; and cost has to be reduced as much as possible without losing diagnostic capability. Design the complete configuration of buckets, sinks and exclusions, with a qualitative estimate of the saving.
Exercise 3: diagnose with an incomplete trace
A customer reports that a product page takes 8 seconds. Looking for the trace, Marta finds: root span GET /catalogo/crampon-02 of 8,100 ms; inside it, query_product of 120 ms and render_template of 90 ms; and nothing else. The remaining 7,890 ms are not covered by any child span. The logs for that request show only one INFO entry at the beginning. Explain what that gap means, list at least four hypotheses with what would tell them apart, and detail what instrumentation you would add so that this case is diagnosable next time.
Solutions
Solution 1
Problems with the original code, seven in all:
| Problem | Severity | Consequence |
|---|---|---|
print instead of logging |
High | No severity, no fields, no trace |
customer_email in the log |
Critical | Personal-data leak, GDPR |
| Data concatenated into the message | High | Impossible to filter or aggregate |
Everything at the implicit INFO severity |
High | An error is indistinguishable from a normal event |
except Exception with no traceback |
High | Where it failed is lost |
| No context in the error | High | "Error: X" does not say which order |
| Rejection recorded as text | Medium | It cannot be counted or analysed |
Rewritten version:
from catalogo.registro import log, trace_fields
import hashlib
def hash_customer(email: str) -> str:
"""Stable hash: allows correlation without identification."""
return hashlib.sha256(email.lower().encode()).hexdigest()[:16]
def process_return(order_id, customer_email, reason):
# Context common to every entry of this operation
context = {
"id_pedido": str(order_id),
"id_cliente_hash": hash_customer(customer_email), # NEVER the email
"motivo": reason,
"operacion": "devolucion",
**trace_fields(), # link with the trace
}
log.info("Return started", extra={"json_fields": context})
try:
order = get_order(order_id)
if order.status != "entregado":
# WARNING, not ERROR: the system works, it is a business rule
log.warning("Return rejected", extra={"json_fields": {
**context,
"resultado": "rechazada",
"causa": "estado_incorrecto",
"estado_pedido": order.status,
"importe_pedido_eur": float(order.amount),
}})
return False
refund = compute_refund(order)
execute_refund(order, refund)
log.info("Return completed", extra={"json_fields": {
**context,
"resultado": "completada",
"importe_reembolso_eur": float(refund),
"dias_desde_entrega": (today() - order.delivery_date).days,
}})
return True
except OrderNotFound:
log.error("Return failed: order does not exist",
extra={"json_fields": {**context, "resultado": "error",
"causa": "pedido_no_encontrado"}})
return False
except RefundGatewayError as e:
# log.exception includes the full traceback automatically
log.exception("Return failed: gateway error",
extra={"json_fields": {**context, "resultado": "error",
"causa": "error_pasarela",
"codigo_pasarela": e.code}})
raise # re-raised: somebody has to find out
except Exception:
log.exception("Return failed: unexpected error",
extra={"json_fields": {**context, "resultado": "error",
"causa": "desconocida"}})
raiseJustification of the most important changes:
- Hashing the email solves the leak without losing investigative capability: customer support applies the same function and finds the entries.
WARNINGfor the rejection by status. It is a deliberate decision: the system did the right thing, there is no fault. If it wereERROR, the alert from 06-04 would fire for perfectly normal returns, feeding the fatigue from section 11 of that lesson.- The
resultadofield with a bounded set of values (completada,rechazada,error) lets you build a complete funnel with a single log-based metric. - Specific exceptions before the generic one. Each records its
causa, which lets you tell a gateway problem apart from a programming error, and they call for very different responses. raiseon the real errors. The original code returnedFalsewhether the order was not returnable or the gateway was down, and that makes them impossible to tell apart from outside.trace_fields()on every entry. What makes the jump in section 15 possible.
The requested query:
resource.type="k8s_container" resource.labels.namespace_name="tienda" jsonPayload.operacion="devolucion" jsonPayload.resultado="rechazada" jsonPayload.causa="estado_incorrecto" timestamp>="2026-07-29T00:00:00Z"
For the average amount, the explorer counts but does not average well. Two options. The quick one, a log-based distribution metric over jsonPayload.importe_pedido_eur with that filter, which gives the p50 and the mean in Cloud Monitoring. The complete one, a sink to BigQuery and SQL:
SELECT
COUNT(*) AS rechazadas,
ROUND(AVG(CAST(JSON_VALUE(jsonPayload.importe_pedido_eur) AS FLOAT64)), 2) AS importe_medio,
JSON_VALUE(jsonPayload.estado_pedido) AS estado
FROM `alpinashop-datos.logs_app.stdout_*`
WHERE _TABLE_SUFFIX BETWEEN '20260729' AND '20260805'
AND JSON_VALUE(jsonPayload.causa) = 'estado_incorrecto'
GROUP BY estado
ORDER BY rechazadas DESC;And an observation that goes beyond the exercise: that breakdown by estado_pedido is product information, not infrastructure information. If it turns out that most of the rejections are orders in the en_transito status, the finding is not technical: it is that there are customers trying to return something they have not yet received, and the interface is probably not explaining that well. Good structured logging ends up answering business questions nobody had thought to ask.
Solution 2
Total volume: 132 GB/month. The load balancer log is 61 % and the Flow Logs 23 %: between them, 84 %. That is where all the headroom is.
Step 1 — Exclusions (the main lever):
| Exclusion | Filter | Estimated saving |
|---|---|---|
| Health checks | httpRequest.requestUrl:"/salud" |
~15 GB/month |
| Static assets 200, 95 % sampled | Asset extensions, status=200 |
~30 GB/month |
| Flow Logs at 0.25 sampling | --logging-flow-sampling=0.25 |
~15 GB/month |
DEBUG in production |
severity=DEBUG |
~2 GB/month |
Resulting ingested volume: around 70 GB/month, close to half. And without losing diagnostic capability: the health checks are already covered by the metrics from 06-04, the static assets keep a 5 % sample which is enough to see trends, and 25 % of the Flow Logs still detects connectivity patterns.
Step 2 — Buckets with differentiated retention:
| Bucket | Contents | Retention | Reason |
|---|---|---|---|
_Default |
Application, LB, SQL, Flow Logs | 30 days | Diagnostic window |
_Required |
Admin audit | 400 days | Fixed and free |
logs-pagos |
jsonPayload.componente="checkout" |
30 days | Careful, see below |
The key decision, and it is counter-intuitive: the logs-pagos bucket is not configured with 7 years of retention. Keeping seven years in a log bucket is by far the most expensive option. The regulation requires keeping the data, it does not require it to be queryable in the Logs Explorer. Hence:
Step 3 — Sinks:
# 1. Compliance: payments to Cloud Storage, with a lifecycle
gcloud logging sinks create sumidero-pagos-archivo \
storage.googleapis.com/alpinashop-logs-pagos \
--log-filter='jsonPayload.componente="checkout" OR jsonPayload.operacion="devolucion"' \
--project=alpinashop-prod
# 2. Analysis: access log to BigQuery, partitioned
gcloud logging sinks create sumidero-acceso-bq \
bigquery.googleapis.com/projects/alpinashop-datos/datasets/logs_acceso \
--log-filter='resource.type="http_load_balancer"' \
--use-partitioned-tables \
--project=alpinashop-prod
# 3. Security: sensitive changes to Pub/Sub
gcloud logging sinks create sumidero-seguridad \
pubsub.googleapis.com/projects/alpinashop-prod/topics/eventos-seguridad \
--log-filter='protoPayload.methodName=~"firewalls\.(insert|patch|delete)" OR protoPayload.methodName="SetIamPolicy"' \
--project=alpinashop-prodWith the archive bucket's lifecycle: Nearline at 30 days, Coldline at 90, Archive at 365, deletion at 2,555 days (7 years). And in BigQuery, partition expiry at 365 days for Lucía's requirement.
Qualitative estimate of the saving:
| Item | Before | After |
|---|---|---|
| Ingestion | 132 GB/month | ~70 GB/month |
| Payment retention | 7 years in a log bucket | Archive in Cloud Storage |
| 12-month analysis | Impossible without long retention | Partitioned BigQuery |
| Diagnostic capability | 30 full days | 30 full days |
The bulk of the saving comes from two places: half the ingested volume and, above all, moving the long retention from the expensive service to the cheap one, where the price difference per GB-month between a log bucket and Archive is two orders of magnitude.
And three warnings that complete the design. First: never exclude errors or audit logs; they are a minimal percentage of the volume and 100 % of the value. Second: verify that the payments sink captures everything the regulation requires before reducing the bucket's retention, because if the filter is wrong, the legal requirement is breached silently. Third: set an alert on the ingested volume with what you learned in 06-04, so you find out if somebody puts a log inside a loop before the bill arrives.
Solution 3
What the gap means. 7,890 of the 8,100 ms are not covered by any span. And that has a very specific meaning: something is happening that the instrumentation cannot see. There are only two families of explanation — uninstrumented code, or waiting time that is not an operation — and telling them apart is the whole exercise.
It is important to notice something: the two spans that do exist are fast. If the problem were in the query or in the rendering, you would see it. The time is going into the space between spans, and that is what has to be investigated.
Four hypotheses, with what tells them apart:
| Hypothesis | What is happening | How to tell it apart |
|---|---|---|
| 1. Uninstrumented external call | A third-party API, a remote cache, an internal service with no instrumentation | VPC Flow Logs: is there outbound traffic in that window? Review the code for urllib, httpx or another client not covered by RequestsInstrumentor |
| 2. Waiting on the connection pool | The request waits for a Cloud SQL connection to be released | Connections metric (06-04): is it at the limit? The query's span is short, but a lot of waiting happened before starting it |
| 3. Blocking by the GIL, CPU or memory | Another request monopolises the process, or there is aggressive garbage collection | Cloud Profiler: flame graph over that window. Pod CPU and memory metrics |
| 4. External network wait | Latency in the response to the client, slow client or TCP problems | Compare total_latencies with backend_latencies in the load balancer's log: if they differ a lot, the time is outside the application |
Which is the most likely and why. Hypothesis 1, and by a piece of reasoning worth spelling out: OpenTelemetry's automatic instrumentation covers Flask, requests and SQLAlchemy. If the code uses any other client — urllib3 directly, a payment provider's SDK, a Redis client, the Firestore library — those calls are completely invisible. And eight seconds with such a clean pattern smells of an external call timeout, very probably one configured at exactly 8 seconds.
Hypothesis 2 is the second candidate and it has a recognisable signature: it shows up under load and disappears when traffic drops. If the problem only happens at peak times, that is the one.
Instrumentation to add, in order of priority:
1. Instrument every outgoing client. The measure that solves the case:
# Add to catalogo/trazas.py
from opentelemetry.instrumentation.urllib3 import URLLib3Instrumentor
from opentelemetry.instrumentation.redis import RedisInstrumentor
from opentelemetry.instrumentation.httpx import HTTPXClientInstrumentor
URLLib3Instrumentor().instrument() # covers SDKs that do not use requests
RedisInstrumentor().instrument()
HTTPXClientInstrumentor().instrument()2. An explicit span around every business operation. The general rule: if an operation can take time, wrap it in a span. It is cheap and it eliminates gaps by construction:
def product_detail(sku):
with tracer.start_as_current_span("product_detail") as span:
span.set_attribute("sku", sku)
with tracer.start_as_current_span("acquire_db_connection"):
conn = pool.acquire() # ← THE POOL WAIT, now visible
with tracer.start_as_current_span("query_product"):
product = query(conn, sku)
with tracer.start_as_current_span("query_ratings"):
ratings = ratings_api.get(sku) # ← the external callThe acquire_db_connection span is especially valuable because it separates waiting time from working time, which is exactly what makes hypothesis 2 look like hypothesis 1.
3. A log on entering and leaving every long operation, with duracion_ms. Even with the span missing, two timestamped log entries bracket where the time went.
4. Explicit, aggressive timeouts on every external client, and a log when they fire:
try:
resp = requests.get(url, timeout=(2, 3)) # connect 2 s, read 3 s
except requests.Timeout:
log.warning("Timeout on the ratings API", extra={"json_fields": {
"servicio": "api_valoraciones", "timeout_s": 3, **trace_fields()}})
ratings = [] # graceful degradation: the page is shown without themThis fourth measure is the most important in the long run, and it goes beyond diagnosis. Without an explicit timeout, most HTTP clients wait indefinitely or for the operating system's default, which can be very long. A service you depend on that degrades drags yours down with it, and eight seconds of waiting is exactly that. With a short timeout and graceful degradation, a downed ratings API produces a page without ratings in 3 seconds instead of a page that does not load in 8.
And the general lesson of the exercise: a gap in a trace is not a failure of the trace, it is information. It is telling you precisely that there is a part of the system you are not observing. The right reaction is not to distrust the tool, but to ask what the code is doing during that interval that nobody instrumented. In this case, almost certainly, waiting for somebody who is not answering.
Conclusion
AlpinaShop has observability's three pillars complete, and — more importantly — it has the links between them.
You know what a structured log entry is and why the difference between textPayload and jsonPayload is the difference between being able to investigate and not being able to. You know all its fields, and you know which is the decisive one: trace, the one that links the log with its trace.
You know where logs come from automatically and which ones have to be enabled explicitly: the load balancer's — among the most valuable there are, with their latency, their country and their CDN result — and VPC Flow Logs. And you know how to emit them properly from Flask, with the five rules: data goes in fields and not in the message, the severity must be right, never personal data, enough context to act on and no noise. With the severity criterion most often got wrong: a retry that works is WARNING; an exhausted one, ERROR.
You have mastered the Logs Explorer and its language — with the : that means "contains" and not "equals" — the three performance tips, and five query patterns that solve real incidents: the errors since a deployment, a specific customer's request located by their hash, who deleted a resource according to the audit logs, the load balancer's slow requests and the image function's errors.
You know log buckets with _Required and _Default, retention with its three horizons — diagnosis, analysis and compliance, each in its right place — and the views that let you grant access to a subset without exposing the audit logs. You know how to create sinks to BigQuery for analysing with SQL, to Cloud Storage for archiving cheaply with a lifecycle and to Pub/Sub for reacting with a function from 06-03, with the writerIdentity everybody forgets. And you know how to use exclusion filters with the percent that samples instead of discarding, with the warning that what is excluded is never recovered and that errors and audit logs are never excluded.
You have log-based metrics — counters and distributions — that instrument without touching the code and feed the alerts from 06-04, with the version label that answers "did this start with yesterday's deployment?" and the same cardinality rule as always.
You know what distributed tracing is: trace and span, context propagation with W3C's traceparent and the X-Cloud-Trace-Context the load balancer is already adding. You know how to instrument Flask with OpenTelemetry — a standard, not a proprietary tool — with automatic instrumentation of Flask, requests and SQLAlchemy, manual spans for your own detail, and the key piece: including the trace_id in every log. You know how to read a waterfall by looking at the three things that matter — which span dominates, whether there are gaps and whether there are repeated spans betraying an N+1 — and you know how to sample with ParentBased(TraceIdRatioBased(...)) so as not to end up with incomplete traces. You know Cloud Profiler and its three cases, with the warning that intuition about where the bottleneck is usually fails.
And you have the complete journey from section 15: from the alert to the metric, from the metric to the log, from the log to the trace and from the trace to the line of code, in seventeen minutes. With the lesson that sums up the whole module: no piece works on its own; the value is in the links, and the link that makes it possible fits in one line of code.
Finally, you know the cost and the three decisions that control it — what is ingested, how long it is kept and where, how much is sampled — with the mistake never to make: saving money by excluding errors, which are the smallest part of the volume and the largest part of the value.
Look now at where AlpinaShop is. The code is on GitHub and gets reviewed. The pipeline builds, tests and deploys on its own. The functions react to events. There are dashboards, alerts, checks from four continents, structured logs, traces and profiles. When something fails, it is known in five minutes and diagnosed in twenty.
And yet all the infrastructure that holds that up — the VPC, the load balancer, the cluster, the alerts you have just created, the sinks you have just configured — still exists because somebody ran the right commands. In 06-05 you saw the problem clearly, you understood what infrastructure as code is, you got to know Deployment Manager and you learned the migration procedure. What is missing is the tool.
In 06-07, the module's last lesson, comes Terraform: the state and why it never goes into Git, the plan and apply flow, AlpinaShop's real code in HCL, modules, importing everything created by hand and the automatic plan on every pull request. And with that, AlpinaShop's infrastructure finally stops living in a terminal's history.
Google Cloud Platform (GCP) Course
Module 1: Introduction to Google Cloud Platform
- What is Google Cloud Platform?
- Setting Up Your GCP Account
- A Tour of the GCP Console
- Projects, Resource Hierarchy and Billing
- Regions, Zones and the Shared Responsibility Model
- Cloud Shell and the gcloud CLI
Module 2: Core GCP Services
- Compute Engine: Virtual Machines on Google Cloud
- Cloud Storage: Object Storage
- Cloud SQL: Managed Relational Databases
- App Engine: Platform as a Service
- Google Kubernetes Engine (GKE)
- NoSQL Databases: Firestore, Bigtable and Spanner
- How to Choose the Right Compute Service
Module 3: Networking and Security
- VPC Networks
- Cloud Load Balancing
- Cloud CDN
- Identity and Access Management (IAM)
- Cloud Armor
- Secrets and Encryption: Secret Manager and Cloud KMS
- Cloud DNS, TLS Certificates and Publishing Services Securely
Module 4: Data and Analytics
- BigQuery: The Analytical Data Warehouse
- Cloud Dataflow: Batch and Streaming Data Processing
- Cloud Dataproc: Managed Spark and Hadoop
- Cloud Pub/Sub: Asynchronous Messaging
- Cloud Data Fusion: Code-Free Data Integration
- Orchestrating Pipelines with Cloud Composer and Workflows
- Data Governance and Dashboards with Dataplex and Looker Studio
Module 5: Machine Learning and AI
- Vertex AI: The Machine Learning Platform on GCP
- AutoML: Custom Models Without Writing Code
- TensorFlow on GCP: Training and Serving Models
- Natural Language API
- Vision API
- Generative AI on Vertex AI: Gemini Models and Embeddings
- MLOps: From Model to Product with Vertex AI Pipelines
Module 6: DevOps and Monitoring
- Cloud Build: Continuous Integration on GCP
- Cloud Source Repositories and Source Code Management
- Cloud Functions: Serverless Functions
- Cloud Monitoring (formerly Stackdriver): Metrics, Dashboards and Alerts
- Cloud Deployment Manager and Native Infrastructure as Code
- Cloud Logging and Cloud Trace: Logs, Traces and Diagnostics
- Terraform on GCP: Infrastructure as Code in Practice
Module 7: Advanced GCP Topics
- Hybrid and Multicloud with Anthos
- Serverless Computing with Cloud Run
- Advanced Networking: Shared VPC, Peering and Hybrid Connectivity
- Security Best Practices
- Cost Management and Optimization
- Reliability: SLOs, High Availability and Disaster Recovery
- Governance at Scale: Organization, Policies and Auditing
