2929# Debug printing control
3030_DISPATCH_DEBUG = os .getenv ("VLLM_FL_DISPATCH_DEBUG" , "0" ) == "1"
3131
32+ # Record which dispatch-level ops are used into the FlagGems oplist file,
33+ # so users can inspect runtime op usage in one place.
34+ _FLAGOS_OPLIST_LOCK = threading .Lock ()
35+ _RECORDED_FLAGOS_OPS : Set [Tuple [str , str ]] = set () # (op_name, impl_id)
36+
37+
38+ def _record_default_flagos_op (op_name : str , impl : OpImpl ) -> None :
39+ """Record dispatch-level op usage into the FlagGems oplist file.
40+
41+ Writes through the FlagGems logger's file handlers directly so that the
42+ record goes via the same file descriptor that FlagGems itself uses. This
43+ avoids a file-position race between two independent file descriptors (the
44+ old ``open(path, "a+")`` approach vs FlagGems' ``FileHandler(mode="w")``)
45+ that caused dispatch entries to be silently overwritten in short-lived
46+ processes such as offline inference.
47+ """
48+ key = (op_name , impl .impl_id )
49+ with _FLAGOS_OPLIST_LOCK :
50+ if key in _RECORDED_FLAGOS_OPS :
51+ return
52+ try :
53+ fg_logger = logging .getLogger ("flag_gems" )
54+ line = (
55+ f"[DEBUG] vllm_fl.dispatch.ops.{ op_name } : { impl .impl_id } "
56+ )
57+ # Write directly through each FlagGems-owned FileHandler so
58+ # that the file position stays synchronised with FlagGems'
59+ # own writes. Using ``logger.debug()`` would prepend an
60+ # unwanted ``[DEBUG] flag_gems.<funcName>:`` prefix added by
61+ # the handler's formatter.
62+ for handler in fg_logger .handlers :
63+ if (
64+ isinstance (handler , logging .FileHandler )
65+ and getattr (handler , "_flaggems_owned" , False )
66+ ):
67+ handler .stream .write (line + "\n " )
68+ handler .stream .flush ()
69+ _RECORDED_FLAGOS_OPS .add (key )
70+ except Exception :
71+ # Never break inference/serving due to diagnostics I/O.
72+ return
73+
3274
3375@dataclass
3476class _OpManagerState :
@@ -485,6 +527,8 @@ def call(self, op_name: str, *args, **kwargs):
485527 f"Op '{ op_name } ' switched from '{ last_impl_id } ' to '{ impl_id } ' "
486528 f"(kind={ impl .kind .value } , vendor={ impl .vendor } )"
487529 )
530+ if impl .kind == BackendImplKind .DEFAULT :
531+ _record_default_flagos_op (op_name , impl )
488532 break
489533 self ._called_ops [op_name ] = impl_id
490534
@@ -526,6 +570,8 @@ def call(self, op_name: str, *args, **kwargs):
526570 f"Op '{ op_name } ' switched from '{ last_impl_id } ' to '{ impl .impl_id } ' "
527571 f"(kind={ impl .kind .value } , vendor={ impl .vendor } )"
528572 )
573+ if impl .kind == BackendImplKind .DEFAULT :
574+ _record_default_flagos_op (op_name , impl )
529575 self ._called_ops [op_name ] = impl .impl_id
530576 else :
531577 # Always log fallback attempts (these are important runtime events)
@@ -540,6 +586,8 @@ def call(self, op_name: str, *args, **kwargs):
540586 if idx > 0 :
541587 with self ._lock :
542588 self ._called_ops [op_name ] = impl .impl_id
589+ if impl .kind == BackendImplKind .DEFAULT :
590+ _record_default_flagos_op (op_name , impl )
543591
544592 return result
545593
0 commit comments