Skip to content

[KUNLUNXIN][BUF-FIX]fix that transformer engine disable benchmark logger #1241

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
kiddyjinjin merged 2 commits into from
Jan 6, 2026
Merged

[KUNLUNXIN][BUF-FIX]fix that transformer engine disable benchmark logger #1241

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
1e25765
[KUNLUNXIN][BUF-FIX]fix that transformer engine disable benchmark logger
dongjibin1996 Dec 19, 2025
481725f
Merge branch 'flagos-ai:master' into KUNLUNXIN]-BUF-FIX]-fix-transfor…
dongjibin1996 Jan 5, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 20 additions & 7 deletions benchmark/conftest.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,8 @@

device = flag_gems.device
vendor_name = flag_gems.vendor_name
recordLogger = logging.getLogger("flag_gems.benchmark.record")
recordLogger.propagate = False


class BenchConfig:
Expand Down Expand Up @@ -165,12 +167,23 @@ def pytest_configure(config):
for arg in config.invocation_params.args
]

logging.basicConfig(
filename="result_{}.log".format("_".join(cmd_args)).replace("_-", "-"),
filemode="w",
level=logging.INFO,
format="[%(levelname)s] %(message)s",
)
log_file = "result_{}.log".format("_".join(cmd_args)).replace("_-", "-")
Comment thread
kiddyjinjin marked this conversation as resolved.

for h in list(recordLogger.handlers):
recordLogger.removeHandler(h)
try:
h.close()
except Exception as e:
import warnings

warnings.warn(f"Failed to close handler: {e}")

handler = logging.FileHandler(log_file, mode="w", encoding="utf-8")
handler.setLevel(logging.INFO)

@SamYuan1990 SamYuan1990 Dec 30, 2025

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

wait a min, the default logger in global level is debug, should we keep the same log level?

@dongjibin1996 dongjibin1996 Dec 31, 2025

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logger is dedicated to recording benchmark results (metrics & JSON summaries) rather than debug traces.

Using logging.INFO is intentional here because we only want to capture the final performance data. Setting it to DEBUG isn't necessary for this purpose and might introduce unwanted noise if we ever add debug logs to this specific logger in the future.

We are strictly maintaining the original behavior, as the previous code also used level=logging.INFO.
bfb5aa19f46f80b5ba8b00d43e3da0a1

handler.setFormatter(logging.Formatter("[%(levelname)s] %(message)s"))
recordLogger.addHandler(handler)
recordLogger.setLevel(logging.INFO)

@SamYuan1990 SamYuan1990 Dec 30, 2025

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

may I know why setLevel twice?

@dongjibin1996 dongjibin1996 Dec 31, 2025 •
edited
Loading

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is necessary because we are configuring a named non-root logger to isolate our benchmark results, which follows the standard Python logging behavior (as seen in the Logging Cookbook ).

Why set level twice?

  1. recordLogger.setLevel(logging.INFO) :
    Purpose : Overrides the default level inheritance.
    Reason : By default, a named logger inherits the Root Logger's level (usually WARNING ). If we don't explicitly set this logger to INFO , our messages will be filtered out before they even reach any handlers.

  2. handler.setLevel(logging.INFO) :
    Purpose : Ensures this specific FileHandler records INFO messages.
    Reason : While strictly setting the Logger level is often sufficient if the Handler is NOTSET , explicitly setting the Handler level is a best practice recommended by the Python docs to guarantee that this specific sink receives the intended logs, regardless of future changes to the logger hierarchy.

So, setting both ensures our log isolation works correctly and robustly."

recordLogger.info("Benchmark record logger enabled")


BUILTIN_MARKS = {
Expand Down Expand Up @@ -239,4 +252,4 @@ def extract_and_log_op_attributes(request):
yield

if Config.record_log and op_attributes:
logging.info(json.dumps(op_attributes, indent=2))
recordLogger.info(json.dumps(op_attributes, indent=2))
7 changes: 3 additions & 4 deletions benchmark/performance_utils.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,6 +1,5 @@
import gc
import importlib
import logging
import os
import time
from typing import Any, Generator, List, Optional, Tuple
Expand All @@ -26,7 +25,7 @@
OperationAttribute,
check_metric_dependencies,
)
from .conftest import Config
from .conftest import Config, recordLogger

torch_backend_device = flag_gems.runtime.torch_backend_device
torch_device_fn = flag_gems.runtime.torch_device_fn
Expand Down Expand Up @@ -372,7 +371,7 @@ def run(self):
shape_desc=self.shape_desc,
)
print(attri)
Comment thread
kiddyjinjin marked this conversation as resolved.
logging.info(attri.to_dict())
recordLogger.info(attri.to_dict())

@SamYuan1990 SamYuan1990 Dec 30, 2025

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorry, I don't get time to go through all 374 lines above.
@kiddyjinjin , do we tested logger = logging.getLogger("flag_gems.benchmark.record") before?

My question: as default logger(logging.getLogger) is able to log file by enable_gems(....), and in this file, which using logging without getLogger seems wrong.

Back to Since this PR focuses on fixing the missing log file issue.... Which means, we confirmed and tested the log file will missing in benchmark testing, when both enable_gems(....) and logging.getLogger configured by design?

@dongjibin1996 dongjibin1996 Dec 31, 2025 •
edited
Loading

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let me clarify the relationship between enable_gems and this fix, and provide evidence for the issue.

  1. Relationship with enable_gems(...) : They are independent.
  • enable_gems(...) configures the runtime debug logger (e.g., logging.getLogger("flag_gems") ) for operator dispatch info.
  • This PR addresses the benchmark result logger (previously using Root Logger, now flag_gems.benchmark.record ), which stores the final performance metrics (JSON).
    Using logging.getLogger in this PR is the correct practice to isolate these two purposes and avoid conflicts.

  1. The Verified Issue: We confirmed that transformer_engine (verified on version 1.13.0+7a6085c with Python 3.10) automatically configures the Root Logger during import. This causes the subsequent logging.basicConfig in our benchmark suite to be ignored (no-op), resulting in missing log files .

  2. Verification Steps: You can verify this conflict with this one-liner:

python -c "import logging; print('Before:', logging.root.handlers); import transformer_engine.
pytorch.cpp_extensions as tex; print('After:', logging.root.handlers)"

Output:

Before: []
After: [<StreamHandler <stderr> (NOTSET)>]  <-- This handler blocks our basicConfig

Conclusion: We have tested that without this fix, pytest ... --record log fails to generate the result file in this environment. This PR fixes it by using a dedicated logger that bypasses the polluted Root Logger.

@SamYuan1990 SamYuan1990 Dec 31, 2025

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@tengqm , I will skip review this PR for now.

FlagGems/benchmark/performance_utils.py

Lines 427 to 428 in 4eda19f

print(result)
logging.info(result.to_json())

I am confusing....it seems we are not using standard pytest or pytest-benchmark plugin....
and this PR just to save metrics result....
seems we have print and logging... so... just pytest xxx > some_file and change result.to_json() from logging.info to print will work?

@kiddyjinjin , @dongjibin1996 please move/go ahead.

return
self.init_user_config()
for dtype in self.to_bench_dtypes:
Expand Down Expand Up @@ -425,7 +424,7 @@ def run(self):
result=metrics,
)
print(result)
Comment thread
kiddyjinjin marked this conversation as resolved.
logging.info(result.to_json())
recordLogger.info(result.to_json())


class GenericBenchmark(Benchmark):
Expand Down
5 changes: 5 additions & 0 deletions benchmark/test_transformer_engine_perf.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,11 @@
try:
from transformer_engine.pytorch import cpp_extensions as tex

# Note: Importing transformer_engine (especially in some versions like on python 3.10) may automatically
# configure the Root Logger (adding handlers). This can cause subsequent `logging.basicConfig` calls
# (used by FlagGems benchmark) to be ignored/no-op, leading to missing result log files.
# See: https://github.com/NVIDIA/TransformerEngine/issues/1065

TE_AVAILABLE = True
except ImportError:
TE_AVAILABLE = False
Expand Down
Loading