How can Python execute a line of code, then display an error indicating a crash at the previous line?

Question

I have a script which contains (among other things) these three lines of code:

(line 138) pdb.set_trace()

(line 140) training_start_time = datetime.now()
(line 141) print(f'Network training beginning at {training_start_time}.')

Here is the output I'm seeing:

> c:\vtcproject\yolov5\roadometry_train.py(140)train()
-> training_start_time = datetime.now()
(Pdb) >? continue
Network training beginning at 2022-02-17 11:23:04.340499.
Traceback (most recent call last):
  File "<input>", line 1, in <module>
  File "C:\Users\Alexander Farley\AppData\Local\JetBrains\Toolbox\apps\PyCharm-P\ch-0\212.5457.59\plugins\python\helpers\pydev\_pydev_bundle\pydev_umd.py", line 198, in runfile
    pydev_imports.execfile(filename, global_vars, local_vars)  # execute the script
  File "C:\Users\Alexander Farley\AppData\Local\JetBrains\Toolbox\apps\PyCharm-P\ch-0\212.5457.59\plugins\python\helpers\pydev\_pydev_imps\_pydev_execfile.py", line 18, in execfile
    exec(compile(contents+"\n", file, 'exec'), glob, loc)
  File "C:/VTCProject/yolov5/roadometry_train.py", line 316, in <module>
    main(opt)
  File "C:/VTCProject/yolov5/roadometry_train.py", line 304, in main
    train(data, cfg, hyp, opt, device)
  File "C:/VTCProject/yolov5/roadometry_train.py", line 140, in train
    training_start_time = datetime.now()
TypeError: 'module' object is not callable

There are a few things I don't understand here.

1. How is it possible to see this print output (network training beginning at...) if the code is crashing at datetime.now()?

2. Why is it that if I manually execute dt = datetime.now() in pdb, then it works fine, but I'm seeing TypeError: 'module' object is not callable if I type continue into pdb or just execute the script without pdb?

The library is imported like this:

(line 13) from datetime import datetime

Answer 1

Well, this turned out to be somewhat complicated.

I removed code from my script until I found something very strange. Further down my script, below the lines listed above, I was eventually entering a loop which created an instance of tqdm for progress updates:

for epoch in range(start_epoch,
                   opt.epochs):
    pbar = enumerate(train_loader)
    pbar = tqdm(pbar, total=nb)  # progress bar

When I commented out the tqdm usage in the loop, the TypeError above (at line 140, according to the exception) disappeared.

Paring everything down reinforced that simply calling tqdm caused this error. Searching the tqdm Github issues, I found this:

https://github.com/tqdm/tqdm/issues/611

There is a post in this discussion indicating that TypeError: 'module' object is not callable can occur if one uses:

import tqdm

instead of:

from tqdm import tqdm

So my analysis of what happened here is that tqdm was simply imported as a module, and obviously calling a module as a new object instance isn't going to work. The only confusing part is why the stated line-number is wrong.

The issue raised on Github corresponds closely to my scenario: creating a PyTorch dataloader which is then passed to tqdm.

I was basing my code on the Ultralytics Yolov5 repo and it appears that I changed from tqdm import tqdm to just import tqdm mistakenly. Specifically importing the class and not just the module causes the TypeError to disappear.

It seems that this error has nothing to do with datetime.now(). After commenting this out, I still get a TypeError, but pointing at a different line - now it blames the actual line trying to create a tqdm instance, which is what I would have expected in the first place.

  File "C:/VTCProject/yolov5/roadometry_debug.py", line 41, in train
    for epoch in range(start_epoch,
TypeError: 'module' object is not callable

In the above output, line 41 of roadometry_debug.py is:

    pbar = tqdm(pbar, total=nb)  # progress bar

While the line number being blamed appears correct, it seems that the error printout is still printing out the wrong line: for epoch in range....

This explains why pdb allows me to manually execute the next line, and the next print-out: because they're not the issue!

I still don't understand why the first error text blames the wrong line of code, or why the 2nd error text prints out the wrong text but the correct line-number.

---

Update: it seems that pdb is causing the reported line numbers in the error message to be incorrect.

Here is a minimal example:

import pdb
import tqdm
from datetime import datetime


def train():

    pdb.set_trace()

    training_start_time = datetime.now()
    print(f'Network training beginning at {training_start_time}.')

    for epoch in range(0,
                       10):  # epoch ------------------------------------------------------------------
        pbar = enumerate([1, 2, 3])
        pbar = tqdm(pbar, total=3)  # progress bar


def main():
    train()

if __name__ == "__main__":
    main()

The error message printed out from the above blames the wrong line:

c:\vtcproject\yolov5\roadometry_debug.py(10)train()
-> training_start_time = datetime.now()
(Pdb) >? continue
Network training beginning at 2022-02-17 18:32:13.892776.
Traceback (most recent call last):
  File "<input>", line 1, in <module>
  File "C:\Users\Alexander Farley\AppData\Local\JetBrains\Toolbox\apps\PyCharm-P\ch-0\212.5457.59\plugins\python\helpers\pydev\_pydev_bundle\pydev_umd.py", line 198, in runfile
    pydev_imports.execfile(filename, global_vars, local_vars)  # execute the script
  File "C:\Users\Alexander Farley\AppData\Local\JetBrains\Toolbox\apps\PyCharm-P\ch-0\212.5457.59\plugins\python\helpers\pydev\_pydev_imps\_pydev_execfile.py", line 18, in execfile
    exec(compile(contents+"\n", file, 'exec'), glob, loc)
  File "C:/VTCProject/yolov5/roadometry_debug.py", line 23, in <module>
    main()
  File "C:/VTCProject/yolov5/roadometry_debug.py", line 20, in main
    train()
  File "C:/VTCProject/yolov5/roadometry_debug.py", line 10, in train
    training_start_time = datetime.now()
TypeError: 'module' object is not callable

If the call to pdb.set_trace() is commented out, the error message blames the correct line.

Script after commenting out relevant line:

import pdb
import tqdm
from datetime import datetime


def train():

    #pdb.set_trace()

    training_start_time = datetime.now()
    print(f'Network training beginning at {training_start_time}.')

    for epoch in range(0,
                       10):  # epoch ------------------------------------------------------------------
        pbar = enumerate([1, 2, 3])
        pbar = tqdm(pbar, total=3)  # progress bar


def main():
    train()

if __name__ == "__main__":
    main()

Output:

Network training beginning at 2022-02-17 18:33:31.278133.
Traceback (most recent call last):
  File "<input>", line 1, in <module>
  File "C:\Users\Alexander Farley\AppData\Local\JetBrains\Toolbox\apps\PyCharm-P\ch-0\212.5457.59\plugins\python\helpers\pydev\_pydev_bundle\pydev_umd.py", line 198, in runfile
    pydev_imports.execfile(filename, global_vars, local_vars)  # execute the script
  File "C:\Users\Alexander Farley\AppData\Local\JetBrains\Toolbox\apps\PyCharm-P\ch-0\212.5457.59\plugins\python\helpers\pydev\_pydev_imps\_pydev_execfile.py", line 18, in execfile
    exec(compile(contents+"\n", file, 'exec'), glob, loc)
  File "C:/VTCProject/yolov5/roadometry_debug.py", line 23, in <module>
    main()
  File "C:/VTCProject/yolov5/roadometry_debug.py", line 20, in main
    train()
  File "C:/VTCProject/yolov5/roadometry_debug.py", line 16, in train
    pbar = tqdm(pbar, total=3)  # progress bar
TypeError: 'module' object is not callable

Notice that the final line-number in the error printout has now changed from 10 (incorrect) to 16 (correct).

It's a reverse heisenbug - only appears if observed!