pytrace

A lightweight Python function tracing tool designed for debugging the Ceph CLI and related utilities. It utilizes sys.settrace and threading.settrace to provide detailed, color-coded execution flow information.

Features

• Specific Function Tracing: Traces a customizable list of functions to keep output focused. It can be configured via environment variables or a configuration file.
• Thread Support: Automatically traces new threads.
• Rich Output:
  • Colorized console output (file names, function names, parameters, return values, and exceptions).
  • Indented call stacks to visualize execution depth.
  • Truncated representations of large objects for readability.
• Environment Driven: Can be toggled via environment variables.

Project Structure

• trace_hook.py: The core tracing logic and hook implementation.
• sitecustomize.py: A standard Python site-customization module that automatically installs the trace hook if the environment is configured correctly.

Installation

Method 1: Automatic via sitecustomize

1. Add this directory to your PYTHONPATH:

   export PYTHONPATH=$PYTHONPATH:/path/to/pytrace

2. The sitecustomize.py will automatically install the hook when PYTRACE_ENABLE is set.

Method 2: Manual Installation

You can manually import and install the hook in any Python script:

import trace_hook
trace_hook.install()

Usage

By default, sitecustomize.py is disabled. To enable tracing, set the environment variable PYTRACE_ENABLE:

export PYTRACE_ENABLE=1

Configuring Functions to Trace

You can configure which functions to trace using either environment variables or a configuration file. If neither is provided, a default list of Ceph-related functions will be used.

1. Using Environment Variable PYTRACE_FUNCS: Provide a comma-separated list of function names to trace:

   export PYTRACE_FUNCS="func1,func2"

   To trace all functions, use *:

   export PYTRACE_FUNCS="*"

2. Using Configuration File: Create a configuration file (default is .pytrace.conf in the current directory) and list the function names, one per line. You can use # for comments. To trace all functions, just write * on the first line. You can specify a custom config file path via PYTRACE_CONF:

   export PYTRACE_CONF="/path/to/your/custom.conf"

Example Output

trace_hook installed
TRACE [CALL] tid=140110605086784 ceph:parse_cmdargs:272 | args=None, target=''
TRACE [RET ] tid=140110605086784 ceph:parse_cmdargs:359 | ret=(ArgumentParser(prog='ceph', usage=None, description='Ceph administration too...
TRACE [CALL] tid=140110605086784 ceph:maybe_daemon_command:784 | parsed_args=Namespace(completion=False, help=False, cephconf=None, input_file=None, outpu..., childargs=[]
TRACE [RET ] tid=140110605086784 ceph:maybe_daemon_command:826 | ret=(False, 0)
TRACE [CALL] tid=140110605086784 ceph_argparse.py:run_in_thread:1525 | func=<class 'rados.Rados'>, *args=(), **kwargs={'name': 'client.admin',  'clustername': None,  'conf_defaults': {'log_to_std...
TRACE [RET ] tid=140110605086784 ceph_argparse.py:run_in_thread:1556 | ret=<rados.Rados object at 0x7f6e03762da0>
TRACE [CALL] tid=140110605086784 ceph_argparse.py:run_in_thread:1525 | func=<bound method Rados.conf_parse_argv of <rados.Rados object at 0x7f6e03762da0>>, *args=([],), **kwargs={}
TRACE [RET ] tid=140110605086784 ceph_argparse.py:run_in_thread:1556 | ret=None
TRACE [CALL] tid=140110605086784 ceph_argparse.py:run_in_thread:1525 | func=<bound method Rados.connect of <rados.Rados object at 0x7f6e03762da0>>, *args=(), **kwargs={'timeout': None}
2026-04-16T15:19:15.467+0800 7f6e036d06c0 -1 WARNING: all dangerous and experimental features are enabled.
2026-04-16T15:19:15.491+0800 7f6e036d06c0 -1 WARNING: all dangerous and experimental features are enabled.
TRACE [RET ] tid=140110605086784 ceph_argparse.py:run_in_thread:1556 | ret=None
TRACE [CALL] tid=140110605086784 ceph_argparse.py:find_cmd_target:1435 | childargs=['status']
TRACE [RET ] tid=140110605086784 ceph_argparse.py:find_cmd_target:1507 | ret=('mon', '')
TRACE [CALL] tid=140110605086784 ceph_argparse.py:json_command:1673 | cluster=<rados.Rados object at 0x7f6e03762da0>, target=('mon', ''), prefix='get_command_descriptions', argdict=None, inbuf=b'', timeout=0, verbose=False
  TRACE [CALL] tid=140110605086784 ceph_argparse.py:send_command_retry:1559 | *args=(<rados.Rados object at 0x7f6e03762da0>, ('mon', ''),  '{"prefix": "get_comma..., **kwargs={}
    TRACE [CALL] tid=140110605086784 ceph_argparse.py:send_command:1573 | cluster=<rados.Rados object at 0x7f6e03762da0>, target=('mon', ''), cmd='{"prefix": "get_command_descriptions"}', inbuf=b'', timeout=0, verbose=False
      TRACE [CALL] tid=140110605086784 ceph_argparse.py:run_in_thread:1525 | func=<bound method Rados.mon_command of <rados.Rados object at 0x7f6e03762da0>>, *args=('{"prefix": "get_command_descriptions"}', b''), **kwargs={'timeout': 0}
      TRACE [RET ] tid=140110605086784 ceph_argparse.py:run_in_thread:1556 | ret=(0,  b'{"cmd000":{"sig":["pg","stat"],"help":"show placement group status.","...
    TRACE [RET ] tid=140110605086784 ceph_argparse.py:send_command:1670 | ret=(0,  b'{"cmd000":{"sig":["pg","stat"],"help":"show placement group status.","...
  TRACE [RET ] tid=140110605086784 ceph_argparse.py:send_command_retry:1562 | ret=(0,  b'{"cmd000":{"sig":["pg","stat"],"help":"show placement group status.","...
TRACE [RET ] tid=140110605086784 ceph_argparse.py:json_command:1723 | ret=(0,  b'{"cmd000":{"sig":["pg","stat"],"help":"show placement group status.","...
TRACE [CALL] tid=140110605086784 ceph:new_style_command:635 | parsed_args=Namespace(completion=False, help=False, cephconf=None, input_file=None, outpu..., cmdargs=['status'], target=('mon', ''), sigdict={'cmd000': {'sig': [argdesc(<class 'ceph_argparse.CephPrefix'>, req=True, pos..., inbuf=b'', verbose=False
  TRACE [CALL] tid=140110605086784 ceph:do_command:578 | parsed_args=Namespace(completion=False, help=False, cephconf=None, input_file=None, outpu..., target=('mon', ''), cmdargs=['status'], sigdict={'cmd000': {'sig': [argdesc(<class 'ceph_argparse.CephPrefix'>, req=True, pos..., inbuf=b'', verbose=False
    TRACE [CALL] tid=140110605086784 ceph_argparse.py:validate_command:1324 | sigdict={'cmd000': {'sig': [argdesc(<class 'ceph_argparse.CephPrefix'>, req=True, pos..., args=['status'], verbose=False
    TRACE [RET ] tid=140110605086784 ceph_argparse.py:validate_command:1432 | ret={'prefix': 'status'}
    TRACE [CALL] tid=140110605086784 ceph_argparse.py:json_command:1673 | cluster=<rados.Rados object at 0x7f6e03762da0>, target=('mon', ''), prefix=None, argdict={'prefix': 'status'}, inbuf=b'', timeout=0, verbose=False
      TRACE [CALL] tid=140110605086784 ceph_argparse.py:send_command_retry:1559 | *args=(<rados.Rados object at 0x7f6e03762da0>, ('mon', ''), '{"prefix": "status"}',..., **kwargs={}
        TRACE [CALL] tid=140110605086784 ceph_argparse.py:send_command:1573 | cluster=<rados.Rados object at 0x7f6e03762da0>, target=('mon', ''), cmd='{"prefix": "status"}', inbuf=b'', timeout=0, verbose=False
          TRACE [CALL] tid=140110605086784 ceph_argparse.py:run_in_thread:1525 | func=<bound method Rados.mon_command of <rados.Rados object at 0x7f6e03762da0>>, *args=('{"prefix": "status"}', b''), **kwargs={'timeout': 0}
          TRACE [RET ] tid=140110605086784 ceph_argparse.py:run_in_thread:1556 | ret=(0,  b'  cluster:\n    id:     2aeaf4a1-ef51-4bc2-bc79-415bf4d97dac\n    heal...
        TRACE [RET ] tid=140110605086784 ceph_argparse.py:send_command:1670 | ret=(0,  b'  cluster:\n    id:     2aeaf4a1-ef51-4bc2-bc79-415bf4d97dac\n    heal...
      TRACE [RET ] tid=140110605086784 ceph_argparse.py:send_command_retry:1562 | ret=(0,  b'  cluster:\n    id:     2aeaf4a1-ef51-4bc2-bc79-415bf4d97dac\n    heal...
    TRACE [RET ] tid=140110605086784 ceph_argparse.py:json_command:1723 | ret=(0,  b'  cluster:\n    id:     2aeaf4a1-ef51-4bc2-bc79-415bf4d97dac\n    heal...
  TRACE [RET ] tid=140110605086784 ceph:do_command:632 | ret=(0,  b'  cluster:\n    id:     2aeaf4a1-ef51-4bc2-bc79-415bf4d97dac\n    heal...
TRACE [RET ] tid=140110605086784 ceph:new_style_command:694 | ret=(0,  b'  cluster:\n    id:     2aeaf4a1-ef51-4bc2-bc79-415bf4d97dac\n    heal...
TRACE [CALL] tid=140110605086784 ceph:raw_write:171 | buf=(b'  cluster:\n    id:     2aeaf4a1-ef51-4bc2-bc79-415bf4d97dac\n    health: ...
TRACE [RET ] tid=140110605086784 ceph:raw_write:173 | ret=None
  cluster:
    id:     2aeaf4a1-ef51-4bc2-bc79-415bf4d97dac
    health: HEALTH_OK

  services:
    mon: 3 daemons, quorum a,b,c (age 2w) [leader: a]
    mgr: x(active, since 2w)
    mds: 1/1 daemons up, 2 standby
    osd: 3 osds: 3 up (since 2w), 3 in (since 2w)

  data:
    volumes: 1/1 healthy
    pools:   4 pools, 177 pgs
    objects: 24 objects, 585 KiB
    usage:   3.0 GiB used, 300 GiB / 303 GiB avail
    pgs:     177 active+clean

TRACE [CALL] tid=140110605086784 ceph_argparse.py:run_in_thread:1525 | func=<bound method Rados.shutdown of <rados.Rados object at 0x7f6e03762da0>>, *args=(), **kwargs={}
TRACE [RET ] tid=140110605086784 ceph_argparse.py:run_in_thread:1556 | ret=None

License

This project is licensed under the MIT License - see the LICENSE file for details.