spulec/freezegun

``PermissionError: [Errno 1] Operation not permitted`` appears when upgrading to ``1.3.0``

psasselum opened this issue · 7 comments

I've not been able to pinpoint exactly what the issue is in freezegun (maybe async code, just a wild guess ?), but I bisected my CI failing to the upgrade from 1.2.2 to 1.3.0. Here's the stacktrace:

self = <_UnixSelectorEventLoop running=False closed=False debug=False>
fd = <MagicMock name='socket().fileno()' id='139676523736240'>
callback = <bound method BaseSelectorEventLoop._read_from_self of <_UnixSelectorEventLoop running=False closed=False debug=False>>
args = (), handle = <Handle BaseSelectorEventLoop._read_from_self()>
    def _add_reader(self, fd, callback, *args):
        self._check_closed()
        handle = events.Handle(callback, args, self, None)
        try:
>           key = self._selector.get_key(fd)
/usr/local/lib/python3.10/asyncio/selector_events.py:256: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <selectors.EpollSelector object at 0x7f08f9947d30>
fileobj = <MagicMock name='socket().fileno()' id='139676523736240'>
    def get_key(self, fileobj):
        """Return the key associated to a registered file object.
    
        Returns:
        SelectorKey for this file object
        """
        mapping = self.get_map()
        if mapping is None:
            raise RuntimeError('Selector is closed')
        try:
            return mapping[fileobj]
        except KeyError:
>           raise KeyError("{!r} is not registered".format(fileobj)) from None
E           KeyError: "<MagicMock name='socket().fileno()' id='139676523736240'> is not registered"
/usr/local/lib/python3.10/selectors.py:193: KeyError
During handling of the above exception, another exception occurred:
args = ()
kwargs = {'caplog': <_pytest.logging.LogCaptureFixture object at 0x7f08f9a983a0>, 'fake_fherd_input': <function fake_fherd_inpu..., 'path_to_directory': PosixPath('/builds/ukyu/zefzefz-fherd-bot/tests/cli/command/use_cases/ikd'), ...}
    def wrapper(*args, **kwargs):
>       with self as time_factory:
/usr/local/lib/python3.10/site-packages/freezegun/api.py:816: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/local/lib/python3.10/site-packages/freezegun/api.py:634: in __enter__
    return self.start()
/usr/local/lib/python3.10/site-packages/freezegun/api.py:739: in start
    event_loop = asyncio.new_event_loop()
/usr/local/lib/python3.10/asyncio/events.py:783: in new_event_loop
    return get_event_loop_policy().new_event_loop()
/usr/local/lib/python3.10/asyncio/events.py:673: in new_event_loop
    return self._loop_factory()
/usr/local/lib/python3.10/asyncio/unix_events.py:64: in __init__
    super().__init__(selector)
/usr/local/lib/python3.10/asyncio/selector_events.py:56: in __init__
    self._make_self_pipe()
/usr/local/lib/python3.10/asyncio/selector_events.py:107: in _make_self_pipe
    self._add_reader(self._ssock.fileno(), self._read_from_self)
/usr/local/lib/python3.10/asyncio/selector_events.py:258: in _add_reader
    self._selector.register(fd, selectors.EVENT_READ,
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
self = <selectors.EpollSelector object at 0x7f08f9947d30>
fileobj = <MagicMock name='socket().fileno()' id='139676523736240'>, events = 1
data = (<Handle BaseSelectorEventLoop._read_from_self()>, None)
    def register(self, fileobj, events, data=None):
        key = super().register(fileobj, events, data)
        poller_events = 0
        if events & EVENT_READ:
            poller_events |= self._EVENT_READ
        if events & EVENT_WRITE:
            poller_events |= self._EVENT_WRITE
        try:
>           self._selector.register(key.fd, poller_events)
E           PermissionError: [Errno 1] Operation not permitted
/usr/local/lib/python3.10/selectors.py:360: PermissionError

Hi @psasselum, can you share a reproducible testcase?

I'm afraid I can't (work codebase), there's a single test failing among a hundred of similar cases and there's nothing distinguishing this one test particularly from the other, so I don't even know how to start to create a reproducer.

The test starts like this:

@freeze_time("2013-04-09 12:05:01", tz_offset=-4)
@mock.patch.dict(
    os.environ,
    {
        # ...
        "TZ": "US/Eastern",
    },
    clear=True,
)
@pytest.mark.parametrize(
    "path_to_directory",
    TEST_CASES_DIRECTORY,
    ids=[str(d.relative_to(USE_CASES_DIRECTORY)) for d in TEST_CASES_DIRECTORY],
)
def test_command(
    path_to_directory: Path,
    fake_fherd_input: Callable,
    mocked_socket: MagicMock,
    caplog: LogCaptureFixture,
) -> None:
    caplog.set_level(logging.DEBUG)
    time.tzset()
    # ...

As I said, only one of the parametrize test over hundred fail, and I don't know why this particular one is failing (it's a simple one without any mocks).

Hmm. That makes things a little trickier. Do you use asyncio in your tests/codebase?

This particular test is a "bad input" use case that fail relatively fast raising an error without launching much code then display the result (with a lib using async). The other use case all display the result with this same lib though.

I think it might be due to async because of this part of the stacktrace:

/usr/local/lib/python3.10/asyncio/selector_events.py:258: in _add_reader
    self._selector.register(fd, selectors.EVENT_READ,
divad commented

It's the same issue as I described in #521 - there relating to pytest-socket.

@psasselum

This bug was most likely due to how freezegun changed how calls to asyncio would behave. Because it caused quite a few bugs, this behaviour is now hidden behind a feature-flag, so freezegun should work again as it did <1.3.0 unless you explicitly enable this.

with freeze_time('1970-01-02', real_asyncio=True):
    ...

This is part of the 1.4.0 release.

Awesome, thank you !