[Python学习笔记-013] 一种Python脚本运行轨迹的查看方法
本文利用sys.settrace() + atexit.register()和inspect模块实现了一种Python脚本运行轨迹的查看方法。
1. 核心模块 - debug.py
1 #!/usr/bin/python3 2 """ 3 debug module for Python programming 4 ----------------------------------- 5 This debug module is for providing ksh-style debugging (by setting a 6 poweful PS4 and set -x) while doing Python programming. 7 8 Q: How to use this feature? 9 A: Pretty easy. Add these two-line code to your Python script 10 e.g. 11 if __name__ == "__main__": 12 + import debug 13 + debug.init() 14 ... 15 16 Note the default debug environment variable is DEBUG, let's just take 17 it for example, 18 19 1. Turn debug on for all functions 20 $ export DEBUG=yes 21 22 2. Turn debug off 23 $ export DEBUG=no 24 25 3. Turn debug on for one function in specific file 26 $ export DEBUG=foo@foo1.py 27 28 4. Turn debug on for a couple of functions 29 $ export DEBUG=foo:foo2:foo3 30 31 5. Turn debug on for all functions in some files 32 $ export DEBUG=@foo1.py:@foo2.py 33 """ 34 35 import sys 36 import os 37 import re 38 import inspect 39 import atexit 40 import time 41 42 43 class Cstr(str): 44 """ 45 Cstr(object) -> Colorful string 46 47 Return a colorful string representation of the object. 48 49 0. togray() : str2gray 50 1. tored() : str2red 51 2. togreen() : str2green 52 3. toyellow() : str2yellow 53 4. toblue() : str2blue 54 5. tomagenta() : str2magenta 55 6. tocyan() : str2cyan 56 7. towhite() : str2white 57 8. tonone() : str2none (color is stripped) 58 59 Examples: 60 (1) s1 = "Hello World" 61 s2 = Cstr(s1) 62 print s2.tored() 63 64 (2) print Cstr("Hello World").tored() 65 66 (3) s1 = Cstr("Hello World").tored() 67 s2 = Cstr(s1).tonone() 68 """ 69 70 def __init__(self, s=""): 71 self.s = s 72 73 def setstr(self, s): 74 self.s = s 75 76 def getstr(self): 77 return self.s 78 79 def _isatty(self): 80 s = os.getenv("ISATTY") 81 if s is None: 82 s = "" 83 84 if s.upper() == "YES": 85 return True 86 if s.upper() == "NO": 87 return False 88 89 if sys.stdout.isatty() and sys.stderr.isatty(): 90 return True 91 return False 92 93 def togray(self): 94 return "\033[1;30m%s\033[m" % self.s if self._isatty() else self.s 95 96 def tored(self): 97 return "\033[1;31m%s\033[m" % self.s if self._isatty() else self.s 98 99 def togreen(self): 100 return "\033[1;32m%s\033[m" % self.s if self._isatty() else self.s 101 102 def toyellow(self): 103 return "\033[1;33m%s\033[m" % self.s if self._isatty() else self.s 104 105 def toblue(self): 106 return "\033[1;34m%s\033[m" % self.s if self._isatty() else self.s 107 108 def tomagenta(self): 109 return "\033[1;35m%s\033[m" % self.s if self._isatty() else self.s 110 111 def tocyan(self): 112 return "\033[1;36m%s\033[m" % self.s if self._isatty() else self.s 113 114 def towhite(self): 115 return "\033[1;37m%s\033[m" % self.s if self._isatty() else self.s 116 117 def tonone(self): 118 s = self.s 119 s = re.sub(r'\033\[1;3.m', '', s) 120 s = re.sub(r'\033\[m', '', s) 121 s = s.strip('\r\n') 122 return s 123 124 125 class Debug(object): 126 """ 127 Debug -> Object 128 129 Customize a callback tracer() which could be used by sys.settrace() 130 131 NOTE: There are some environment variables which can be reset from shell 132 o DEBUG_UTAG : debug unique tag, default is "__DEBUG__: " 133 o TRACER_RPATH_DEPTH : relative path depth of file, default is 0 134 o TRACER_SLEEP_NSECS : nsecs to sleep befor printing debug info to 135 stderr, default is 0 136 o TRACER_VERBOSE : verbose level to print when "return" is 137 being traced, can be one of 0, 1, 2, and 3, 138 default is 0 139 if >= 1, print caller 140 if >= 2, print caller and locals 141 if >= 3, print caller, locals and globals 142 143 Examples: 144 (1) foo = Debug() 145 sys.settrace(foo.tracer) 146 147 (2) foo = Debug("XXX_DEBUG") 148 sys.settrace(foo.tracer) 149 150 (3) foo = Debug("DEBUG", True) 151 sys.settrace(foo.tracer) 152 """ 153 def __init__(self, env="DEBUG", dumpvars=False): 154 self.debug_envname = env 155 self.debug = "no" 156 self.dumpvars = dumpvars 157 158 self.debug_utag_envname = "DEBUG_UTAG" 159 self.debug_utag = "__DEBUG__: " 160 161 self.tracer_rpath_depth_envname = "TRACER_RPATH_DEPTH" 162 self.tracer_sleep_nsecs_envname = "TRACER_SLEEP_NSECS" 163 self.tracer_verbose_envname = "TRACER_VERBOSE" 164 self.tracer_rpath_depth = 0 165 self.tracer_sleep_nsecs = 0 166 self.tracer_verbose = 0 167 self.tracer_outfile = "/tmp/debug.vars" 168 self.tracer_start_time = time.time() 169 170 s = os.getenv(self.debug_envname) 171 if s is not None and len(s) > 0: 172 self.debug = s 173 174 s = os.getenv(self.debug_utag_envname) 175 if s is not None and len(s) > 0: 176 self.debug_utag = s 177 178 s = os.getenv(self.tracer_rpath_depth_envname) 179 if s is not None and len(s) > 0: 180 self.tracer_rpath_depth = int(s.split(':')[-1]) 181 182 s = os.getenv(self.tracer_sleep_nsecs_envname) 183 if s is not None and len(s) > 0: 184 self.tracer_sleep_nsecs = int(s) 185 186 s = os.getenv(self.tracer_verbose_envname) 187 if s is not None and len(s) > 0: 188 self.tracer_verbose = int(s) 189 190 if self.dumpvars: 191 with open(self.tracer_outfile, 'w') as fd: 192 fd.write("%s=%s\n" % (self.debug_envname, self.debug)) 193 fd.write("%s='%s'\n" % (self.debug_utag_envname, 194 self.debug_utag)) 195 fd.write("%s=%d\n" % (self.tracer_rpath_depth_envname, 196 self.tracer_rpath_depth)) 197 fd.write("%s=%d\n" % (self.tracer_sleep_nsecs_envname, 198 self.tracer_sleep_nsecs)) 199 fd.write("%s=%d\n" % (self.tracer_verbose_envname, 200 self.tracer_verbose)) 201 202 def _debug_query(self, funcname="", filename=""): 203 """ 204 1. If debug is in ['no', 'off', 'none'], return False 205 2. If debug is in ['yes', 'on', 'all'], return True 206 3. for obj in funcname@filename funcname @filename: 207 if obj is in debug.split(':') 208 return True 209 """ 210 s = self.debug.lower() 211 if s in ['no', 'none', 'off']: 212 return False 213 if s in ['yes', 'all', 'on']: 214 return True 215 216 l_obj = ['', '', ''] 217 l_obj[0] = funcname + '@' + filename.split('/')[-1] 218 l_obj[1] = funcname 219 l_obj[2] = '@' + filename.split('/')[-1] 220 for obj in l_obj: 221 if obj in self.debug.split(":"): 222 return True 223 224 return False 225 226 def _get_caller(self, frame): 227 prevframe = frame.f_back 228 229 try: 230 prevlineno = prevframe.f_lineno 231 except: 232 prevlineno = -1 233 234 try: 235 prevfuncname = prevframe.f_code.co_name 236 except: 237 prevfuncname = "None" 238 239 try: 240 prevfilename = prevframe.f_code.co_filename 241 except: 242 prevfilename = "None" 243 244 s = "%s@%s:%d" % (prevfuncname, prevfilename, prevlineno) 245 return s 246 247 def tracer(self, frame, event, arg): 248 #print Cstr("1:FRAME: " + str(frame)).tocyan() 249 #print Cstr("2:EVENT: " + event).toblue() 250 #print Cstr("3:ARG: " + str(arg)).tored() 251 252 # 253 # Reference: https://pymotw.com/2/sys/tracing.html 254 # 255 # NOTE: c_call, c_return, and c_exception are not supported 256 # to be traced 257 # 258 if event in ["line", "return", "call", "exception"]: 259 seconds = int(time.time() - self.tracer_start_time) 260 lineno = frame.f_lineno 261 funcname = frame.f_code.co_name 262 filename = frame.f_code.co_filename 263 264 # 265 # For /usr/lib/python*/*.py, always print 266 # its absolute path 267 # 268 if not filename.startswith("/usr/lib"): 269 n = self.tracer_rpath_depth 270 filename = '/'.join(filename.split('/')[n:]) 271 272 flag = self._debug_query(funcname, filename) 273 if not flag: 274 return None 275 276 try: 277 thisframe = inspect.getsourcelines(frame) 278 lineno_base = thisframe[1] 279 lineno_offset = lineno - lineno_base 280 lineco = thisframe[0][lineno_offset].rstrip() 281 except: 282 errmsg = "-- Oops, source code not found --" 283 lineco = Cstr(errmsg).tomagenta() 284 285 s = self.debug_utag 286 s += Cstr('[').togray() 287 s += Cstr(funcname).tomagenta() + '()' 288 s += Cstr('@').togray() 289 s += Cstr(filename).toblue() 290 s += Cstr(':').togray() 291 s += Cstr("%d" % lineno).togray() 292 s += Cstr('|').togray() 293 s += Cstr("%d" % seconds).tomagenta() 294 s += Cstr(']').togray() 295 if event == "line": 296 s += '+ ' + lineco 297 298 elif event == "return": 299 s0 = s 300 301 rtag = "<RETURN>" 302 s += "++ %s ++ %s" % \ 303 (Cstr(rtag).tocyan(), 304 Cstr(str(arg)).tocyan()) 305 306 if self.tracer_verbose >= 3: 307 rtag = "<GLOBALS>" 308 gvars = str(frame.f_globals) 309 s += '\n' + s0 310 s += "++ %s ++ %s" % \ 311 (Cstr(rtag).tocyan(), 312 Cstr(gvars).tocyan()) 313 314 if self.tracer_verbose >= 2: 315 rtag = "<LOCALS>" 316 try: 317 arg_info = \ 318 inspect.getargvalues(frame) 319 lvars = str(arg_info.locals) 320 except: 321 lvars = "" 322 s += '\n' + s0 323 s += "++ %s ++ %s" % \ 324 (Cstr(rtag).tocyan(), 325 Cstr(lvars).tocyan()) 326 327 if self.tracer_verbose >= 1: 328 rtag = "</CALLER>" 329 sprev = self._get_caller(frame) 330 s += '\n' + s0 331 s += "++ %s ++ %s" % \ 332 (Cstr(rtag).tocyan(), 333 Cstr(sprev).tocyan()) 334 335 elif event == "call": 336 s0 = s 337 338 if self.tracer_verbose >= 1: 339 rtag = "<CALLER> " 340 sprev = self._get_caller(frame) 341 s += "++ %s ++ %s" % \ 342 (Cstr(rtag).tocyan(), 343 Cstr(sprev).tocyan()) 344 s += '\n' + s0 345 346 try: 347 arg_info = inspect.getargvalues(frame) 348 funcargs = str(arg_info.locals) 349 except: 350 funcargs = "" 351 fd4 = 'def ' + funcname + funcargs + ':' 352 s += '++ ' + Cstr(fd4).tocyan() 353 354 elif event == "exception": 355 s += '++ ' + Cstr(str(arg)).tored() 356 357 else: 358 pass 359 360 if self.tracer_sleep_nsecs != 0: 361 time.sleep(self.tracer_sleep_nsecs) 362 363 sys.stderr.write("%s\n" % s) 364 365 return self.tracer 366 367 368 def init(env="DEBUG", dumpvars=False): 369 atexit.register(fini) 370 371 dbg = Debug(env, dumpvars) 372 sys.settrace(dbg.tracer) 373 374 375 def fini(): 376 # 377 # NOTE: If we don't reset sys.settrace(), such an exception is printed 378 # to stderr once 'call' is traced 379 # 380 # Exception TypeError: "'NoneType' object is not callable" in \ 381 # <function _remove at 0xb740ecdc> ignored 382 # 383 # To trace all functions called, try: 384 # $ python -m trace --listfuncs <foo.py> 385 # $ python -m trace --trace <foo.py> 386 # 387 sys.settrace(None)
2 - demo程序 - foo.py
1 #!/usr/bin/python3 2 3 import sys 4 5 6 def foo(a, b): 7 return (a * 10) if a > b else (b * 100) 8 9 10 def main(argc, argv): 11 if argc != 3: 12 print("Usage: %s <a> <b>" % argv[0], file=sys.stderr) 13 return 1 14 15 a = int(argv[1]) 16 b = int(argv[2]) 17 ret = foo(a, b) 18 print(ret) 19 20 return 0 21 22 23 if __name__ == '__main__': 24 import debug 25 debug.init() 26 sys.exit(main(len(sys.argv), sys.argv))
注意：上述脚本插入了关键的两行：
import debug debug.init()
3 - 运行效果
4 - 小结
在纯函数式编程中，上述运行轨迹查看方法可以使Python脚本执行过程一目了然，不失为一把Python代码辅助阅读的利器。但是，上述方法在实现时未考虑打印类名和异常，故有待进一步增强。
