Skip to content

Commit 52f937b

Browse files
authored
Prevent duplicate output in 3.14 (#415)
* Prevent duplicate output in 3.14 * Register explicit profiler atexit hook only in main process (fix multiprocessing / Py3.14 regression) (#5) * Fix explicit profiler ownership for multiprocessing * Avoid helper process atexit registration * Skip atexit output in forked children * Refine ownership checks for explicit profiler * Add debug hooks and reduce CI matrix * Skip orphaned forkserver output * Restore full CI matrix * Disable debug lines * simplify fix * Fix doctest * Add typing to explicit profiler while working on it * Fix type error * Fix typing * wip
1 parent 3aa7504 commit 52f937b

6 files changed

Lines changed: 265 additions & 54 deletions

File tree

CHANGELOG.rst

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ Changes
33

44
5.0.1
55
~~~~~
6+
* FIX: Prevented duplicate or inconsistent profiler output under Python 3.14 when multiprocessing is used.
67
* ENH: Add %%lprun_all for more beginner-friendly profiling in IPython/Jupyter #383
78
* FIX: mitigate speed regressions introduced in 5.0.0
89
* ENH: Added capability to combine profiling data both programmatically (``LineStats.__add__()``) and via the CLI (``python -m line_profiler``) (#380, originally proposed in #219)

line_profiler/explicit_profiler.py

Lines changed: 179 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -163,14 +163,30 @@ def func4():
163163
164164
The core functionality in this module was ported from :mod:`xdev`.
165165
"""
166+
from __future__ import annotations
166167
import atexit
168+
import multiprocessing
167169
import os
170+
import pathlib
168171
import sys
172+
import typing
173+
from typing import Any, Callable
174+
175+
if typing.TYPE_CHECKING:
176+
ConfigArg = str | pathlib.PurePath | bool | None
177+
178+
169179
# This is for compatibility
170180
from .cli_utils import boolean, get_python_executable as _python_command
171181
from .line_profiler import LineProfiler
172182
from .toml_config import ConfigSource
173183

184+
# The first process that enables profiling records its PID here. Child processes
185+
# created via multiprocessing (spawn/forkserver) inherit this environment value,
186+
# which helps prevent helper processes from claiming ownership and clobbering
187+
# output. Standalone subprocess runs should always be able to reset this value.
188+
_OWNER_PID_ENVVAR: str = 'LINE_PROFILER_OWNER_PID'
189+
174190

175191
class GlobalProfiler:
176192
"""
@@ -179,16 +195,15 @@ class GlobalProfiler:
179195
The :py:obj:`line_profile.profile` decorator is an instance of this object.
180196
181197
Arguments:
182-
config (Union[str, PurePath, bool, None]):
198+
config (str | PurePath | bool | None):
183199
Optional TOML config file from which to load the
184200
configurations (see Attributes);
185201
if not explicitly given (= :py:data:`True` or
186202
:py:data:`None`), it is either resolved from the
187203
:envvar:`!LINE_PROFILER_RC` environment variable or looked
188204
up among the current directory or its ancestors. Should all
189205
that fail, the default config file at
190-
``importlib.resources.path('line_profiler.rc', \
191-
'line_profiler.toml')`` is used;
206+
``importlib.resources.path('line_profiler.rc', 'line_profiler.toml')`` is used;
192207
passing :py:data:`False` disables all lookup and falls back
193208
to the default configuration
194209
@@ -258,14 +273,24 @@ class GlobalProfiler:
258273
>>> self.show()
259274
"""
260275

261-
def __init__(self, config=None):
276+
_config: pathlib.PurePath | None
277+
_profile: LineProfiler | None
278+
_owner_pid: int | None
279+
enabled: bool | None
280+
281+
setup_config: dict[str, list[str]]
282+
write_config: dict[str, Any]
283+
show_config: dict[str, Any]
284+
output_prefix: str
285+
286+
def __init__(self, config: ConfigArg = None) -> None:
262287
# Remember which config file we loaded settings from
263288
config_source = ConfigSource.from_config(config)
264289
self._config = config_source.path
265290

266291
self._profile = None
292+
self._owner_pid = None
267293
self.enabled = None
268-
269294
# Configs:
270295
# - How to toggle the profiler
271296
self.setup_config = config_source.conf_dict['setup']
@@ -280,7 +305,7 @@ def __init__(self, config=None):
280305
# supplied `config`)
281306
self.show_config.pop('column_widths')
282307

283-
def _kernprof_overwrite(self, profile):
308+
def _kernprof_overwrite(self, profile: LineProfiler) -> None:
284309
"""
285310
Kernprof will call this when it runs, so we can use its profile object
286311
instead of our own. Note: when kernprof overwrites us we wont register
@@ -290,7 +315,7 @@ def _kernprof_overwrite(self, profile):
290315
self._profile = profile
291316
self.enabled = True
292317

293-
def _implicit_setup(self):
318+
def _implicit_setup(self) -> None:
294319
"""
295320
Called once the first time the user decorates a function with
296321
``line_profiler.profile`` and they have not explicitly setup the global
@@ -306,29 +331,96 @@ def _implicit_setup(self):
306331
else:
307332
self.disable()
308333

309-
def enable(self, output_prefix=None):
334+
def enable(self, output_prefix: str | None = None) -> None:
310335
"""
311336
Explicitly enables global profiler and controls its settings.
337+
338+
Notes:
339+
Multiprocessing start methods like 'spawn'/'forkserver' can create
340+
helper/bootstrap interpreters that import this module. Those helpers
341+
must not claim ownership or register an atexit hook, otherwise they can
342+
clobber output from the real script process.
312343
"""
344+
self._debug("enable:ENTER")
345+
346+
if is_mp_bootstrap():
347+
self._debug("enable:skip-mp-bootstrap")
348+
self.enabled = False
349+
return
350+
351+
if self._should_skip_due_to_owner():
352+
self._debug("enable:skip-due-to-owner")
353+
self.enabled = False
354+
return
355+
356+
owner_pid = os.getpid()
357+
os.environ[_OWNER_PID_ENVVAR] = str(owner_pid)
358+
self._owner_pid = owner_pid
359+
self._debug("enable:owner-claimed", owner_pid=owner_pid)
360+
313361
if self._profile is None:
314-
# Try to only ever create one real LineProfiler object
315362
atexit.register(self.show)
316-
self._profile = LineProfiler() # type: ignore
363+
self._profile = LineProfiler()
317364

318-
# The user can call this function more than once to update the final
319-
# reporting or to re-enable the profiler after it a disable.
320365
self.enabled = True
321-
322366
if output_prefix is not None:
323367
self.output_prefix = output_prefix
324368

325-
def disable(self):
369+
def _should_skip_due_to_owner(self) -> bool:
370+
"""
371+
Return True if another process has already claimed ownership.
372+
373+
The first process to enable profiling records its PID in an env var.
374+
Child interpreters can inherit that value; they must not steal ownership.
375+
"""
376+
owner = os.environ.get(_OWNER_PID_ENVVAR)
377+
if not owner:
378+
self._debug("owner:no-owner-env")
379+
return False
380+
381+
current = str(os.getpid())
382+
if owner == current:
383+
self._debug("owner:is-us", owner=owner)
384+
return False
385+
386+
if is_mp_bootstrap():
387+
self._debug("owner:skip-mp-bootstrap", owner=owner, current=current)
388+
return True
389+
390+
# Standalone run: allow this interpreter to become the owner.
391+
self._debug("owner:allow-standalone-reset", owner=owner, current=current)
392+
return False
393+
394+
def _debug(self, message: str, **extra: Any) -> None:
395+
if not os.environ.get('LINE_PROFILER_DEBUG'):
396+
return
397+
try:
398+
parent = multiprocessing.parent_process()
399+
parent_pid = parent.pid if parent is not None else None
400+
except Exception:
401+
parent_pid = None
402+
403+
pid = os.getpid()
404+
405+
info: dict[str, Any] = {
406+
'ppid': os.getppid(),
407+
'process': getattr(multiprocessing.current_process(), 'name', None),
408+
'parent_pid': parent_pid,
409+
'owner_env': os.environ.get(_OWNER_PID_ENVVAR),
410+
'owner_pid': self._owner_pid,
411+
'enabled': self.enabled,
412+
}
413+
info.update(extra)
414+
payload = ' '.join(f'{k}={v!r}' for k, v in info.items())
415+
print(f'[line_profiler debug {pid=}] {message} {payload}')
416+
417+
def disable(self) -> None:
326418
"""
327419
Explicitly initialize and disable this global profiler.
328420
"""
329421
self.enabled = False
330422

331-
def __call__(self, func):
423+
def __call__(self, func: Callable) -> Callable:
332424
"""
333425
If the global profiler is enabled, decorate a function to start the
334426
profiler on function entry and stop it on function exit. Otherwise
@@ -349,31 +441,43 @@ def __call__(self, func):
349441
self._implicit_setup()
350442
if not self.enabled:
351443
return func
352-
return self._profile(func)
444+
assert self._profile is not None
445+
446+
wrapped = self._profile(func)
447+
return wrapped
353448

354-
def show(self):
449+
def show(self) -> None:
355450
"""
356451
Write the managed profiler stats to enabled outputs.
357452
358453
If the implicit setup triggered, then this will be called by
359454
:py:mod:`atexit`.
360455
"""
456+
self._debug('show:enter')
457+
owner_env = os.environ.get(_OWNER_PID_ENVVAR)
458+
if os.getppid() == 1 and owner_env == str(os.getpid()):
459+
self._debug('show:skip-orphan-owner', owner_env=owner_env)
460+
return
461+
if self._owner_pid is not None and os.getpid() != self._owner_pid:
462+
self._debug('show:skip-non-owner', current_pid=os.getpid())
463+
return
361464
import io
362-
import pathlib
363465

364466
write_stdout = self.write_config['stdout']
365467
write_text = self.write_config['text']
366468
write_timestamped_text = self.write_config['timestamped_text']
367469
write_lprof = self.write_config['lprof']
368470

471+
assert self._profile is not None
472+
473+
kwargs: dict[str, Any] = {'config': self._config, **self.show_config}
369474
if write_stdout:
370-
kwargs = {'config': self._config, **self.show_config}
371475
self._profile.print_stats(**kwargs)
372476

373477
if write_text or write_timestamped_text:
374478
stream = io.StringIO()
375479
# Text output always contains details, and cannot be rich.
376-
text_kwargs = {**kwargs, 'rich': False, 'details': True}
480+
text_kwargs: dict[str, Any] = {**kwargs, 'rich': False, 'details': True}
377481
self._profile.print_stats(stream=stream, **text_kwargs)
378482
raw_text = stream.getvalue()
379483

@@ -401,6 +505,61 @@ def show(self):
401505
+ str(lprof_output_fpath))
402506

403507

508+
def is_mp_bootstrap() -> bool:
509+
"""
510+
True when this interpreter invocation looks like multiprocessing
511+
bootstrapping/plumbing, where we must not claim ownership / write outputs.
512+
513+
Example:
514+
>>> # xdoctest: +SKIP('can be flaky at test time')
515+
>>> import pytest
516+
>>> if is_mp_bootstrap():
517+
... pytest.skip('Cannot test mp bootstrap detection from within an mp bootstrap process')
518+
>>> import sys, subprocess, textwrap
519+
>>> code = textwrap.dedent(r'''
520+
... import multiprocessing as mp
521+
... from line_profiler.explicit_profiler import is_mp_bootstrap
522+
...
523+
... def child(q):
524+
... q.put(is_mp_bootstrap())
525+
...
526+
... if __name__ == "__main__":
527+
... ctx = mp.get_context("spawn")
528+
... q = ctx.Queue()
529+
... p = ctx.Process(target=child, args=(q,))
530+
... p.start()
531+
... val = q.get()
532+
... p.join()
533+
... print(val)
534+
... ''')
535+
>>> out = subprocess.check_output([sys.executable, "-c", code], text=True).strip()
536+
>>> out in {"True", "False"}
537+
True
538+
"""
539+
try:
540+
import multiprocessing.spawn as mp_spawn
541+
if getattr(mp_spawn, "_inheriting", False):
542+
return True
543+
except Exception:
544+
pass
545+
546+
orig = getattr(sys, "orig_argv", None) or []
547+
if any(a.startswith("--multiprocessing") for a in orig):
548+
return True
549+
if any("multiprocessing.forkserver" in a for a in orig):
550+
return True
551+
if any("multiprocessing.spawn" in a for a in orig):
552+
return True
553+
554+
try:
555+
if multiprocessing.current_process().name != "MainProcess":
556+
return True
557+
except Exception:
558+
pass
559+
560+
return False
561+
562+
404563
# Construct the global profiler.
405564
# The first time it is called, it will be initialized. This is usually a
406565
# NoOpProfiler unless the user requested the real one.

line_profiler/explicit_profiler.pyi

Lines changed: 0 additions & 33 deletions
This file was deleted.

line_profiler/line_profiler.pyi

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -117,7 +117,7 @@ class LineProfiler(CLineProfiler, ByCountProfilerMixin):
117117
# Fallback: just wrap the `.__call__()` of a generic callable
118118

119119
@overload
120-
def __call__(self, func: Callable) -> FunctionType:
120+
def __call__(self, func: Callable) -> Callable:
121121
...
122122

123123
def add_callable(

tests/test_complex_case.py

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -95,6 +95,8 @@ def test_varied_complex_invocations():
9595
temp_dpath = stack.enter_context(tempfile.TemporaryDirectory())
9696
stack.enter_context(ub.ChDir(temp_dpath))
9797
env = {}
98+
# Can enable if this breaks again
99+
# env['LINE_PROFILER_DEBUG'] = '1'
98100

99101
outpath = case['outpath']
100102
if outpath:

0 commit comments

Comments
 (0)