# Logging A: Why print Is Not Logging, and the Log Levels<no value>

## What will we learn?

- What a **Log** is and why real systems write one.
- Why **`print` is not Logging**.
- Python's **`logging`** module.
- The **five levels** of the log: `debug`, `info`, `warning`, `error`, `critical`.

## Why do we need this?

The server you will write in the backend and databases topics will run **without anyone watching it**, maybe on a computer in the cloud, in the middle of the night. Tomorrow morning a customer will say "my order disappeared during the night". How will you know what happened?

- `print` printed to a screen nobody saw, and it is already gone.
- The Debugger does not help, because the bug happened **yesterday**, not now.

**The log** is a "black box" like in an airplane: a record of what happened, when, and how serious it was. Every professional system writes logs, and developers read them every day.

## Explanation from the basics

### What is a Log?

A **Log** is a sequence of **records**. Each record describes one event: **when** it happened, **how serious** it is, and **what** happened.

```text
2026-10-06 09:14:02 INFO     User dana logged in
2026-10-06 09:14:30 WARNING  Login attempt with wrong password for avi
2026-10-06 09:15:11 ERROR    Payment failed for order 1042: card declined
```

### Why `print` is not Logging

| | `print` | `logging` |
|---|---|---|
| **Time** | None. You do not know when it happened. | Automatic in every record |
| **Severity** | All the messages look the same | 5 levels. You can filter |
| **Turning off/on** | You have to delete or add lines of code | Change **one setting**, without touching the code |
| **Destination** | Only the screen | Screen, **file**, a log server... |
| **On a server** | Gets lost | Saved and checked later |

**Rule:** `print` is for communicating with the **user** (the program's output). `logging` is for communicating with **developers and operations people** (what happened inside the program).

### The five levels

| Level | Number | When to use it | Example |
|---|---|---|---|
| `DEBUG` | 10 | Technical details for the developer, during development and debugging | `"cart contents: [...]"` |
| `INFO` | 20 | Normal, important events — "everything is fine" | `"user dana logged in"` |
| `WARNING` | 30 | Something unusual, but the system continues | `"disk 90% full"`, `"retrying request"` |
| `ERROR` | 40 | An action **failed** | `"payment failed for order 1042"` |
| `CRITICAL` | 50 | The whole system is in danger and may not be able to continue | `"database unreachable - shutting down"` |

### The minimum level — filtering

You set a **minimum level**, and only messages **from it and above** are shown:

- During development: `DEBUG`. You see everything.
- On a real server (Production): `INFO` or `WARNING`. Only what matters, without "noise".

**Python's default is `WARNING`.** So if you do not configure anything, `debug` and `info` messages **are not shown at all**.

{{< box "analogy" "Analogy: a hospital alert system" >}}
**DEBUG** = the full record of every measurement (only the research doctor looks at it). **INFO** = "the patient got lunch". **WARNING** = "temperature slightly high, keep watching". **ERROR** = "a medicine was not given on time". **CRITICAL** = "code blue!". The night-shift nurse chooses to see only WARNING and above, otherwise the messages would drown them.
{{< /box >}}

## Syntax

```python
import logging

# configure once, at the start of the program
logging.basicConfig(
    level=logging.INFO,                                  # minimum level to show
    format="%(asctime)s %(levelname)s %(message)s",      # how each record looks
)

# write log records
logging.debug("technical details")
logging.info("normal important event")
logging.warning("something unusual")
logging.error("an operation failed")
logging.critical("the whole system is in danger")
```

**Common fields in `format`:**

| Field | What is shown |
|---|---|
| `%(asctime)s` | Date and time |
| `%(levelname)s` | The level's name (`INFO`, `ERROR`...) |
| `%(message)s` | Your message |
| `%(funcName)s` | The name of the function that wrote the record |
| `%(lineno)d` | The line number |

## First code example

`week-2/log_levels.py`:

```python
import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s %(levelname)s %(message)s",
)

logging.debug("This is a debug message")
logging.info("Application started")
logging.warning("Config file not found, using defaults")
logging.error("Could not connect to the payment service")
logging.critical("Out of memory - shutting down")
```

**Output:**

```text
2026-10-06 09:30:12,481 INFO Application started
2026-10-06 09:30:12,481 WARNING Config file not found, using defaults
2026-10-06 09:30:12,482 ERROR Could not connect to the payment service
2026-10-06 09:30:12,482 CRITICAL Out of memory - shutting down
```

## Breaking down the code line by line

| Line | Explanation |
|---|---|
| `import logging` | Python's built-in module for logs. No installation needed. |
| `logging.basicConfig(...)` | A **one-time** setup at the start of the program: what the minimum level is and what each record looks like. |
| `level=logging.INFO` | Show only from INFO and above. |
| `format="..."` | The record's template: time, level, message. |
| `logging.debug(...)` | **Not shown!** DEBUG (10) is lower than INFO (20), so it was filtered out. |
| `logging.info(...)` to `logging.critical(...)` | Shown, because they are at level INFO and above. |
| `,481` in the output | Milliseconds. Useful when many events happen in the same second. |

**Try it:** change to `level=logging.DEBUG` and run again. Now 5 lines appear. With `level=logging.ERROR` only 2 appear. **You changed one line, and did not touch the messages themselves.** That is the power of levels.

## Another example

**Logs inside a real program**, combined with Exceptions from the previous lessons. `week-2/orders.py`:

```python
import logging

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s %(levelname)-8s %(funcName)s: %(message)s",
)

STOCK = {"bread": 5, "milk": 0, "eggs": 12}

def place_order(product, quantity):
    logging.debug("place_order called with product=%s quantity=%s", product, quantity)

    if product not in STOCK:
        logging.error("Unknown product requested: %s", product)
        return False

    available = STOCK[product]
    if available == 0:
        logging.warning("Product out of stock: %s", product)
        return False

    if quantity > available:
        logging.warning("Not enough %s: requested %s, available %s", product, quantity, available)
        return False

    STOCK[product] = available - quantity
    logging.info("Order placed: %s x%s (left in stock: %s)", product, quantity, STOCK[product])
    return True

place_order("bread", 2)
place_order("milk", 1)
place_order("cake", 1)
place_order("eggs", 20)
```

**Output:**

```text
2026-10-06 09:41:03,115 DEBUG    place_order: place_order called with product=bread quantity=2
2026-10-06 09:41:03,115 INFO     place_order: Order placed: bread x2 (left in stock: 3)
2026-10-06 09:41:03,116 DEBUG    place_order: place_order called with product=milk quantity=1
2026-10-06 09:41:03,116 WARNING  place_order: Product out of stock: milk
2026-10-06 09:41:03,116 DEBUG    place_order: place_order called with product=cake quantity=1
2026-10-06 09:41:03,116 ERROR    place_order: Unknown product requested: cake
2026-10-06 09:41:03,117 DEBUG    place_order: place_order called with product=eggs quantity=20
2026-10-06 09:41:03,117 WARNING  place_order: Not enough eggs: requested 20, available 12
```

**Breakdown:**

- `%(levelname)-8s` — the `-8` pads the level's name to 8 characters, so the messages are aligned in a column. Easy to read.
- `%(funcName)s` — you see **which function** each record came from.
- `logging.info("... %s ...", product, quantity)` — `%s` is a **placeholder** for a value, and the values are passed as extra arguments. This is the recommended way in logging: the text is built only if the message will really be shown, so filtered-out DEBUG messages cost almost nothing.
- **Choosing the levels:** "ordered" is INFO (a normal, important event). "Out of stock" is WARNING (the business works, but it is worth knowing). "Product does not exist" is ERROR (something is wrong in the request, maybe a bug on the client side). The call details are DEBUG.
- `if product not in STOCK` — `in` on a dict checks whether the **key** exists.

Now change to `level=logging.WARNING`: the log will show only the 3 problems. That is what it will look like on a real server, where only the faults are interesting.

## Common mistake

**Mistake 1: calling `basicConfig` after a message was already written, or twice.**

```python
import logging
logging.info("starting")                     # uses the default config!
logging.basicConfig(level=logging.INFO)      # ignored - already configured
logging.info("now?")                         # still not shown
```

The first call to `logging.info` automatically sets up the default (`WARNING`), and a late `basicConfig` is silently **ignored**. **`basicConfig` always first, and once**, right after the `import`.

**Mistake 2: "I don't see my info".** The reason is almost always the default `WARNING`. The fix: `level=logging.INFO` (or `DEBUG`).

**Mistake 3: the wrong level.**

```python
logging.error("User dana logged in")       # not an error!
logging.info("Payment failed!")            # this IS an error
```

A wrong level makes the filtering useless: whoever looks only at ERROR will miss a failed payment, and be flooded with ordinary logins.

**Mistake 4: logging sensitive information.** `logging.info("login: user=dana password=1234")` — **never** passwords, credit card numbers or tokens. Logs are read by many people and kept for a long time.

<!-- exercises:start — generated by scripts/intro6/sync_site_exercises.py; edit scripts/intro6/exercises/ -->
## Practice

The exercises use only what was taught in this lesson and the lessons before it. Try on your own first, and only then open the solution.

### Exercise 1: Which level?

For each event — at which log level would you record it: DEBUG, INFO, WARNING, ERROR or CRITICAL?

1. A user logged in successfully.
2. The value of a variable inside a loop, while looking for a bug.
3. A user typed a wrong password.
4. The payment failed.
5. There is no connection to the database, and the server cannot work at all.

{{< solution >}}
1. **INFO** — a normal event that is important to record.
2. **DEBUG** — technical details that are relevant only during development.
3. **WARNING** — something unusual, but the system keeps working.
4. **ERROR** — an action failed.
5. **CRITICAL** — the whole system cannot work.
{{< /solution >}}

### Exercise 2: The minimum level

```python
import logging

logging.basicConfig(level=logging.WARNING)

logging.debug("checking item 3")
logging.info("order 17 created")
logging.warning("stock is low: 2 left")
logging.error("payment failed for order 17")
```

Which of the messages will appear, and why? What do you need to change to see all of them?

{{< solution >}}
Only **WARNING** and **ERROR** will appear:

```text
WARNING:root:stock is low: 2 left
ERROR:root:payment failed for order 17
```

`level=logging.WARNING` is a **minimum level**: only messages at this level and above are shown. To see all of them, change to `level=logging.DEBUG`. Without touching the rest of the code — that is the whole advantage.
{{< /solution >}}

### Exercise 3: From print to logging

Replace each `print` with the suitable log level, and set a format with time, level and message:

```python
def withdraw(balance, amount):
    print("withdraw called with", amount)
    if amount > balance:
        print("not enough money, balance is", balance)
        return balance
    print("withdrew", amount)
    return balance - amount
```

{{< solution >}}
```python
import logging

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s %(levelname)-8s %(message)s",
)


def withdraw(balance, amount):
    logging.debug("withdraw called with %s", amount)
    if amount > balance:
        logging.error("not enough money, balance is %s", balance)
        return balance
    logging.info("withdrew %s", amount)
    return balance - amount


withdraw(100, 30)
withdraw(100, 500)
```

- Entering the function — **DEBUG**, a successful withdrawal — **INFO**, a failure — **ERROR**.
- The format adds time and level to every line, for example: `2026-11-01 10:15:02 ERROR    not enough money, balance is 100`.
{{< /solution >}}

### Exercise 4: Reading a log line

```text
2026-11-01 09:14:30 WARNING  Wrong password for avi
```

1. What is each part of the line, and which part of the `format` setting creates it?
2. Why is it important that the line has a time?

{{< solution >}}
1. The parts:
   - `2026-11-01 09:14:30` — the time, created by `%(asctime)s`.
   - `WARNING` — the level, created by `%(levelname)s`.
   - `Wrong password for avi` — the message, created by `%(message)s`.
2. When something happens on the server at three in the morning, the time lets you reconstruct **what happened and in which order**, and cross-check it with other events.
{{< /solution >}}

### Exercise 5: print or logging?

For each case — print or logging? Explain.

1. A program that asks the user for their name and greets them.
2. A server that runs all night, and in the morning you want to know which orders failed.
3. A temporary check of a variable's value during development, which you want to turn off without deleting it.

{{< solution >}}
1. **print** — this is the output the program shows **to the user**.
2. **logging** (ERROR) — information **for the developer**, with time and level, that can be saved and searched.
3. **logging** (DEBUG) — you can turn off all the DEBUG messages with one line (raising the minimum level), without deleting code.

The rule: **print for the user, logging for the developer.**
{{< /solution >}}

<!-- exercises:end -->

## Summary

- **Log** = a record of events: when, how serious, and what happened. The software's "black box".
- `print` = output for the user. `logging` = a record for developers: time, level, filtering and destinations.
- 5 levels: **DEBUG < INFO < WARNING < ERROR < CRITICAL**. Only messages from the minimum level and above are shown.
- The default is **WARNING**. `basicConfig` is called **once, first**.
- `logging.info("x=%s", x)` is the recommended form. And never log passwords.

<!-- docs:start — generated by scripts/intro6/site_docs.py; edit the links there -->

## Official documentation

- [Logging HOWTO — When to use logging](https://docs.python.org/3/howto/logging.html#when-to-use-logging)
- [logging — Logging Levels](https://docs.python.org/3/library/logging.html#logging-levels)

<!-- docs:end -->