multithreading traceback KeyError when modifying file

[MichaelAllen]

BPO	25872
Nosy	@akuchling, @csabella, @miss-islington, @tirkarthi, @mgraczyk, @rahul-kumi, @iritkatriel, @uniocto
PRs	[2.7] bpo-25872: fix KeyError on race in linecache.checkcache() #12061 bpo-25872: Fix KeyError in linecache when multithreaded #17360 bpo-25872: Fix KeyError in linecache when multithreaded #18007 [3.8] bpo-25872: Fix KeyError using linecache from multiple threads (GH-20079) #20079 [3.8] bpo-25872: Fix KeyError in linecache when multithreaded (GH-18007) #20092 [3.7] bpo-25872: Fix KeyError in linecache when multithreaded (GH-18007) (GH-20092) #20511 bpo-25872: Add unit tests for linecache and threading #25913 [3.10] bpo-25872: Add unit tests for linecache and threading (GH-25913) #26208 [3.9] bpo-25872: Add unit tests for linecache and threading (GH-25913) #26211 [3.10] bpo-25872: Add unit tests for linecache and threading (GH-25913) #26212

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2021-05-18.14:27:03.157>
created_at = <Date 2015-12-15.17:21:04.333>
labels = ['easy', 'type-bug', 'library', '3.9']
title = 'multithreading traceback KeyError when modifying file'
updated_at = <Date 2021-05-18.14:27:03.156>
user = 'https://bugs.python.org/MichaelAllen'

bugs.python.org fields:

activity = <Date 2021-05-18.14:27:03.156>
actor = 'iritkatriel'
assignee = 'none'
closed = True
closed_date = <Date 2021-05-18.14:27:03.157>
closer = 'iritkatriel'
components = ['Library (Lib)']
creation = <Date 2015-12-15.17:21:04.333>
creator = 'Michael Allen'
dependencies = []
files = []
hgrepos = []
issue_num = 25872
keywords = ['patch', 'easy']
message_count = 12.0
messages = ['256469', '323180', '359390', '359392', '359427', '370301', '370302', '381409', '393187', '393872', '393874', '393875']
nosy_count = 10.0
nosy_names = ['akuchling', 'python-dev', 'Michael Allen', 'cheryl.sabella', 'miss-islington', 'xtreak', 'Michael Graczyk', 'rahul-kumi', 'iritkatriel', 'uniocto']
pr_nums = ['12061', '17360', '18007', '20079', '20092', '20511', '25913', '26208', '26211', '26212']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue25872'
versions = ['Python 3.9']

[MichaelAllen]

Modifying a file while getting a stacktrace across multiple threads causes linecache's cache to bust and del to be called on the global cache variable. This is not thread safe and raises a KeyError.

Reproducible with,

import threading
import traceback

def main():
    with open(__file__, 'a') as fp:
        fp.write(' ')
        traceback.format_stack()

threads = [
    threading.Thread(target=main)
    for i in range(100)
]
map(lambda t: t.start(), threads)
map(lambda t: t.join(), threads)

I see the following error,

Exception in thread Thread-56:
Traceback (most recent call last):
  File "/Users/me/.pyenv/versions/2.7.10/lib/python2.7/threading.py", line 810, in __bootstrap_inner
    self.run()
  File "/Users/me/.pyenv/versions/2.7.10/lib/python2.7/threading.py", line 763, in run
    self.__target(*self.__args, **self.__kwargs)
  File "test.py", line 7, in main
    traceback.format_stack()
  File "/Users/me/.pyenv/versions/2.7.10/lib/python2.7/traceback.py", line 279, in format_stack
    return format_list(extract_stack(f, limit))
  File "/Users/me/.pyenv/versions/2.7.10/lib/python2.7/traceback.py", line 305, in extract_stack
    linecache.checkcache(filename)
  File "/Users/me/.pyenv/versions/2.7.10/lib/python2.7/linecache.py", line 69, in checkcache
    del cache[filename]
KeyError: 'test.py'

Possible solution is to ignore KeyError on del cache[filename].

[tirkarthi]

It seems there was a major refactor in traceback module with 6bc2c1e where this was fixed in Python 3. Ignoring the KeyError seems reasonable to me.

Thanks

[csabella]

As @XTreak said, this looks like it was fixed for Python 3 and was only an issue for 2.7, so I'm closing the issue.

[mgraczyk]

This issue still exists in Python 3. The repro just needs to be changed so that the threads are actually started.

- map(lambda t: t.start(), threads)
- map(lambda t: t.join(), threads)
+ [t.start() for t in threads]
+ [t.join() for t in threads]

My fix is linked.

[tirkarthi]

Thanks Michael, reopening. I was wrong while trying the reproducer since map is lazy in Python 3 and threads were not executed.

[miss-islington]

New changeset b86636b by Andrew Kuchling in branch '3.8':
[3.8] bpo-25872: Fix KeyError in linecache when multithreaded (GH-18007) (GH-20092)
b86636b

[miss-islington]

New changeset 852e8a7 by Miss Islington (bot) in branch '3.7':
[3.8] bpo-25872: Fix KeyError in linecache when multithreaded (GH-18007) (GH-20092)
852e8a7

[iritkatriel]

The issue was fixed but a unit test for this still needs to be added.

[uniocto]

I apologize if this is rude, as I am not familiar with this method.
I created a following PR to add unit tests about this issue.

#25913

I would be happy to receive feedback on the PR.

[iritkatriel]

New changeset 373741a by Irit Katriel in branch '3.10':
[3.10] bpo-25872: Add unit tests for linecache and threading (GH-25913) (GH-26212)
373741a

[iritkatriel]

New changeset c05d8a6 by Irit Katriel in branch '3.9':
bpo-25872: Add unit tests for linecache and threading (GH-25913) (GH-26211)
c05d8a6

[iritkatriel]

@uniocto - thank you for the tests.