1# Orca 2# 3# Copyright 2005-2008 Sun Microsystems Inc. 4# 5# This library is free software; you can redistribute it and/or 6# modify it under the terms of the GNU Lesser General Public 7# License as published by the Free Software Foundation; either 8# version 2.1 of the License, or (at your option) any later version. 9# 10# This library is distributed in the hope that it will be useful, 11# but WITHOUT ANY WARRANTY; without even the implied warranty of 12# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU 13# Lesser General Public License for more details. 14# 15# You should have received a copy of the GNU Lesser General Public 16# License along with this library; if not, write to the 17# Free Software Foundation, Inc., Franklin Street, Fifth Floor, 18# Boston MA 02110-1301 USA. 19 20"""Provides debug utilities for Orca. Debugging is managed by a debug 21level, which is held in the debugLevel field. All other methods take 22a debug level, which is compared to the current debug level to 23determine if the content should be output.""" 24 25__id__ = "$Id$" 26__version__ = "$Revision$" 27__date__ = "$Date$" 28__copyright__ = "Copyright (c) 2005-2008 Sun Microsystems Inc." 29__license__ = "LGPL" 30 31import inspect 32import traceback 33import os 34import pyatspi 35import re 36import subprocess 37import sys 38 39from datetime import datetime 40 41# Used to turn off all debugging. 42# 43LEVEL_OFF = 10000 44 45# Used to describe events of considerable importance and which will prevent 46# normal program execution. 47# 48LEVEL_SEVERE = 1000 49 50# Used to describe events of interest to end users or system managers or which 51# indicate potential problems, but which Orca can deal with without crashing. 52# 53LEVEL_WARNING = 900 54 55# Used to indicate reasonably significant messages that make sense to end users 56# and system managers. 57# 58# For the purposes of Orca, LEVEL_INFO means display the text being sent to 59# speech and braille. 60# 61LEVEL_INFO = 800 62 63# Used to indicate static configuration information to assist in debugging 64# problems that may be associated with a particular configuration. 65# 66# For the purposes of Orca, LEVEL_CONFIGURATION means display the various 67# aspects of whether a particular feature (e.g., speech, braille, etc.) 68# is enabled or not as well as details about that feature. 69# 70LEVEL_CONFIGURATION = 700 71 72# Used for lowest volume of detailed tracing information. 73# 74# For the purposes of Orca, this is braille and keyboard input, script 75# activation and deletion, locus of focus changes, and visual changes 76# to the locus of focus. 77# 78LEVEL_FINE = 600 79 80# Used for medium volume of detailed tracing information. 81# 82# For the purposes of Orca, this is for debugging speech and braille 83# generators and tracking the synthesis of device events. 84# 85LEVEL_FINER = 500 86 87# Used for maximum volume of detailed tracing information. 88# 89# For the purposes of Orca, this is for tracking all AT-SPI object 90# events. NOTE that one can up the debug level of AT-SPI object 91# events by setting the eventDebugLevel. In addition, one can filter 92# events by setting eventDebugFilter to a regular expression that 93# matches event type names. 94# 95LEVEL_FINEST = 400 96 97# Used for all detailed tracing information, even finer than LEVEL_FINEST 98# 99LEVEL_ALL = 0 100 101debugLevel = LEVEL_SEVERE 102 103# The debug file. If this is not set, then all debug output is done 104# via stdout. If this is set, then all debug output is sent to the 105# file. This can be useful for debugging because one can pass in a 106# non-buffered file to better track down hangs. 107# 108debugFile = None 109 110# The debug filter should be either None (which means to match all 111# events) or a compiled regular expression from the 're' module (see 112# http://www.amk.ca/python/howto/regex/). The regular expression will 113# be used as a matching function - if the event type creates a match 114# in the regular expression, then it will be considered for output. A 115# typical call to this method might look like: 116# 117# debug.eventDebugFilter = rc.compile('focus:|window:activate') 118# 119eventDebugLevel = LEVEL_FINEST 120eventDebugFilter = None 121 122# If True, we output debug information for the event queue. We 123# use this in addition to log level to prevent debug logic from 124# bogging down event handling. 125# 126debugEventQueue = False 127 128# What module(s) should be traced if traceit is being used. By default 129# we'll just attend to ourself. (And by default, we will not enable 130# traceit.) Note that enabling this functionality will drag your system 131# to a complete and utter halt and should only be used in extreme 132# desperation by developers who are attempting to reproduce a very 133# specific, immediate issue. Trust me. :-) Disabling braille monitor in 134# this case is also strongly advised. 135# 136TRACE_MODULES = ['orca'] 137 138# Specific modules to ignore with traceit. 139# 140TRACE_IGNORE_MODULES = ['traceback', 'linecache', 'locale', 'gettext', 141 'logging', 'UserDict', 'encodings', 'posixpath', 142 'genericpath', 're'] 143 144# Specific apps to trace with traceit. 145# 146TRACE_APPS = [] 147 148# What AT-SPI event(s) should be traced if traceit is being used. By 149# default, we'll trace everything. Examples of what you might wish to 150# do to narrow things down include: 151# 152# TRACE_EVENTS = ['object:state-changed', 'focus:'] 153# (for any and all object:state-changed events plus focus: events) 154# TRACE_EVENTS = ['object:state-changed:selected'] 155# (if you know the exact event type of interest) 156# 157TRACE_EVENTS = [] 158 159# What pyatspi role(s) should be traced if traceit is being used. By 160# default, we'll trace everything. An example of what you might wish 161# to do to narrow things down, if you know buttons trigger the problem: 162# 163# TRACE_ROLES = [pyatspi.ROLE_PUSH_BUTTON, pyatspi.ROLE_TOGGLE_BUTTON] 164# 165TRACE_ROLES = [] 166 167# Whether or not traceit should only trace the work being done when 168# processing an actual event. This is when most bad things happen. 169# So we'll default to True. 170# 171TRACE_ONLY_PROCESSING_EVENTS = True 172 173objEvent = None 174 175def printException(level): 176 """Prints out information regarding the current exception. 177 178 Arguments: 179 - level: the accepted debug level 180 """ 181 182 if level >= debugLevel: 183 println(level) 184 traceback.print_exc(100, debugFile) 185 println(level) 186 187def printStack(level): 188 """Prints out the current stack. 189 190 Arguments: 191 - level: the accepted debug level 192 """ 193 194 if level >= debugLevel: 195 println(level) 196 traceback.print_stack(None, 100, debugFile) 197 println(level) 198 199def println(level, text="", timestamp=False): 200 """Prints the text to stderr unless debug is enabled. 201 202 If debug is enabled the text will be redirected to the 203 file debugFile. 204 205 Arguments: 206 - level: the accepted debug level 207 - text: the text to print (default is a blank line) 208 """ 209 210 if level >= debugLevel: 211 text = text.replace("\ufffc", "[OBJ]") 212 if timestamp: 213 text = text.replace("\n", "\n%s" % (" " * 18)) 214 text = "%s - %s" % (datetime.now().strftime("%H:%M:%S.%f"), text) 215 if debugFile: 216 try: 217 debugFile.writelines([text, "\n"]) 218 except TypeError: 219 text = "TypeError when trying to write text" 220 debugFile.writelines([text, "\n"]) 221 except: 222 text = "Exception when trying to write text" 223 debugFile.writelines([text, "\n"]) 224 else: 225 try: 226 sys.stderr.writelines([text, "\n"]) 227 except TypeError: 228 text = "TypeError when trying to write text" 229 sys.stderr.writelines([text, "\n"]) 230 except: 231 text = "Exception when trying to write text" 232 sys.stderr.writelines([text, "\n"]) 233 234def printResult(level, result=None): 235 """Prints the return result, along with information about the 236 method, arguments, and any errors encountered.""" 237 238 if level < debugLevel: 239 return 240 241 stack = inspect.stack() 242 current, prev = stack[1], stack[2] 243 frame = current[0] 244 245 # To better print arguments which are accessible objects 246 args = inspect.getargvalues(frame) 247 for key, value in list(args.locals.items()): 248 args.locals[key] = str(value) 249 fArgs = str.replace(inspect.formatargvalues(*args), "'", "") 250 251 callString = 'CALL: %s.%s (line %s) -> %s.%s%s' % ( 252 inspect.getmodulename(prev[1]), prev[3], prev[2], 253 inspect.getmodulename(current[1]), current[3], fArgs) 254 string = '%s\n%s %s' % (callString, 'RESULT:', result) 255 println(level, '%s' % string) 256 257def printObjectEvent(level, event, sourceInfo=None, timestamp=False): 258 """Prints out an Python Event object. The given level may be 259 overridden if the eventDebugLevel is greater. Furthermore, only 260 events with event types matching the eventDebugFilter regular 261 expression will be printed. 262 263 Arguments: 264 - level: the accepted debug level 265 - event: the Python Event to print 266 - sourceInfo: additional string to print out 267 """ 268 269 if eventDebugFilter and not eventDebugFilter.match(event.type): 270 return 271 272 level = max(level, eventDebugLevel) 273 274 anydata = event.any_data 275 if isinstance(anydata, str) and len(anydata) > 100: 276 anydata = "%s (...)" % anydata[0:100] 277 278 text = "OBJECT EVENT: %s (%d, %d, %s)" \ 279 % (event.type, event.detail1, event.detail2, anydata) 280 println(level, text, timestamp) 281 282 if sourceInfo: 283 println(level, "%s%s" % (' ' * 18, sourceInfo), timestamp) 284 285def printInputEvent(level, string, timestamp=False): 286 """Prints out an input event. The given level may be overridden 287 if the eventDebugLevel (see setEventDebugLevel) is greater. 288 289 Arguments: 290 - level: the accepted debug level 291 - string: the string representing the input event 292 """ 293 294 println(max(level, eventDebugLevel), string, timestamp) 295 296def printDetails(level, indent, accessible, includeApp=True, timestamp=False): 297 """Lists the details of the given accessible with the given 298 indentation. 299 300 Arguments: 301 - level: the accepted debug level 302 - indent: a string containing spaces for indentation 303 - accessible: the accessible whose details are to be listed 304 - includeApp: if True, include information about the app 305 """ 306 307 if level >= debugLevel and accessible: 308 println(level, 309 getAccessibleDetails(level, accessible, indent, includeApp), 310 timestamp) 311 312def statesToString(acc, indent=""): 313 try: 314 states = acc.getState().getStates() 315 except: 316 return "%sstates=(exception)" % indent 317 318 return "%sstates='%s'" % (indent, " ".join(map(pyatspi.stateToString, states))) 319 320def relationsToString(acc, indent=""): 321 try: 322 relations = [r.getRelationType() for r in acc.getRelationSet()] 323 except: 324 return "%srelations=(exception)" % indent 325 326 return "%srelations='%s'" % (indent, " ".join(map(pyatspi.relationToString, [r for r in relations]))) 327 328def interfacesToString(acc, indent=""): 329 try: 330 interfaces = pyatspi.listInterfaces(acc) 331 except: 332 return "%sinterfaces=(exception)" % indent 333 334 return "%sinterfaces='%s'" % (indent, " ".join(interfaces)) 335 336def attributesToString(acc, indent=""): 337 try: 338 attributes = acc.getAttributes() 339 except: 340 return "%sattributes=(exception)" % indent 341 342 return "%sattributes='%s'" % (indent, re.sub("\s+", " ", ", ".join(attributes))) 343 344def getAccessibleDetails(level, acc, indent="", includeApp=True): 345 """Returns a string, suitable for printing, that describes the 346 given accessible. 347 348 Arguments: 349 - indent: A string to prefix the output with 350 - includeApp: If True, include information about the app 351 for this accessible. 352 """ 353 354 if level < debugLevel: 355 return "" 356 357 if includeApp: 358 try: 359 app = acc.getApplication() 360 except: 361 string = indent + "app=(exception getting app) " 362 app = None 363 else: 364 if app: 365 try: 366 string = indent + "app.name='%s' " % app.name 367 except (LookupError, RuntimeError): 368 string = indent + "app.name='(exception getting name)' " 369 else: 370 string = indent + "app=None " 371 else: 372 string = indent 373 374 try: 375 name_string = "name='%s'".replace("\n", "\\n") % acc.name 376 except: 377 name_string = "name=(exception)" 378 379 try: 380 desc_string = "%sdescription='%s'".replace("\n", "\\n") % (indent, acc.description) 381 except: 382 desc_string = "%sdescription=(exception)" % indent 383 384 try: 385 role_string = "role='%s'" % acc.getRoleName() 386 except: 387 role_string = "role=(exception)" 388 389 try: 390 path_string = "%spath=%s" % (indent, pyatspi.getPath(acc)) 391 except: 392 path_string = "%spath=(exception)" % indent 393 394 state_string = statesToString(acc, indent) 395 rel_string = relationsToString(acc, indent) 396 iface_string = interfacesToString(acc, indent) 397 attr_string = attributesToString(acc, indent) 398 399 try: 400 string += "%s %s\n%s\n%s\n%s\n%s\n%s\n%s\n" \ 401 % (name_string, role_string, desc_string, state_string, rel_string, 402 iface_string, attr_string, path_string) 403 except: 404 string += "(exception fetching data)" 405 406 return string 407 408# The following code originated from the following URL: 409# 410# http://www.dalkescientific.com/writings/diary/archive/ \ 411# 2005/04/20/tracing_python_code.html 412# 413import linecache 414 415def _getFileAndModule(frame): 416 filename, module = None, None 417 try: 418 filename = frame.f_globals["__file__"] 419 module = frame.f_globals["__name__"] 420 except: 421 pass 422 else: 423 if (filename.endswith(".pyc") or filename.endswith(".pyo")): 424 filename = filename[:-1] 425 426 return filename, module 427 428def _shouldTraceIt(): 429 if not objEvent: 430 return not TRACE_ONLY_PROCESSING_EVENTS 431 432 eventSource = objEvent.source 433 if TRACE_APPS: 434 app = objEvent.host_application or eventSource.getApplication() 435 try: 436 app = objEvent.host_application or eventSource.getApplication() 437 except: 438 pass 439 else: 440 if not app.name in TRACE_APPS: 441 return False 442 443 if TRACE_ROLES and not eventSource.getRole() in TRACE_ROLES: 444 return False 445 446 if TRACE_EVENTS and \ 447 not [x for x in map(objEvent.type.startswith, TRACE_EVENTS) if x]: 448 return False 449 450 return True 451 452def traceit(frame, event, arg): 453 """Line tracing utility to output all lines as they are executed by 454 the interpreter. This is to be used by sys.settrace and is for 455 debugging purposes. 456 457 Arguments: 458 - frame: is the current stack frame 459 - event: 'call', 'line', 'return', 'exception', 'c_call', 'c_return', 460 or 'c_exception' 461 - arg: depends on the event type (see docs for sys.settrace) 462 """ 463 464 if not _shouldTraceIt(): 465 return None 466 467 filename, module = _getFileAndModule(frame) 468 if not (filename and module): 469 return traceit 470 if module in TRACE_IGNORE_MODULES: 471 return traceit 472 if TRACE_MODULES and not module.split('.')[0] in TRACE_MODULES: 473 return traceit 474 if not event in ['call', 'line', 'return']: 475 return traceit 476 477 lineno = frame.f_lineno 478 line = linecache.getline(filename, lineno).rstrip() 479 output = 'TRACE %s:%s: %s' % (module, lineno, line) 480 481 if event == 'call': 482 argvals = inspect.getargvalues(frame) 483 keys = [x for x in argvals[0] if x != 'self'] 484 try: 485 values = list(map(argvals[3].get, keys)) 486 except TypeError: 487 if len(keys) == 1 and isinstance(keys[0], list): 488 values = list(map(argvals[3].get, keys[0])) 489 else: 490 return traceit 491 for i, key in enumerate(keys): 492 output += '\n ARG %s=%s' % (key, values[i]) 493 494 lineElements = line.strip().split() 495 if lineElements and lineElements[0] == 'return': 496 if event == 'line': 497 return traceit 498 output = '%s (rv: %s)' % (output, arg) 499 500 println(LEVEL_ALL, output) 501 502 return traceit 503 504def getOpenFDCount(pid): 505 procs = subprocess.check_output([ 'lsof', '-w', '-Ff', '-p', str(pid)]) 506 procs = procs.decode('UTF-8').split('\n') 507 files = list(filter(lambda s: s and s[0] == 'f' and s[1:].isdigit(), procs)) 508 509 return len(files) 510 511def getCmdline(pid): 512 try: 513 openFile = os.popen('cat /proc/%s/cmdline' % pid) 514 cmdline = openFile.read() 515 openFile.close() 516 except: 517 cmdline = '(Could not obtain cmdline)' 518 cmdline = cmdline.replace('\x00', ' ') 519 520 return cmdline 521 522def pidOf(procName): 523 openFile = subprocess.Popen('pgrep %s' % procName, 524 shell=True, 525 stdout=subprocess.PIPE).stdout 526 pids = openFile.read() 527 openFile.close() 528 return [int(p) for p in pids.split()] 529 530def examineProcesses(force=False): 531 if force: 532 level = LEVEL_OFF 533 else: 534 level = LEVEL_ALL 535 536 desktop = pyatspi.Registry.getDesktop(0) 537 println(level, 'INFO: Desktop has %i apps:' % desktop.childCount, True) 538 for i, app in enumerate(desktop): 539 pid = app.get_process_id() 540 cmd = getCmdline(pid) 541 fds = getOpenFDCount(pid) 542 try: 543 name = app.name 544 except: 545 name = 'ERROR: Could not get name' 546 else: 547 if name == '': 548 name = 'WARNING: Possible hang' 549 println(level, '%3i. %s (pid: %s) %s file descriptors: %i' \ 550 % (i+1, name, pid, cmd, fds), True) 551 552 # Other 'suspect' processes which might not show up as accessible apps. 553 otherApps = ['apport'] 554 for app in otherApps: 555 pids = pidOf(app) 556 if not pids: 557 println(level, 'INFO: no pid for %s' % app, True) 558 continue 559 560 for pid in pids: 561 cmd = getCmdline(pid) 562 fds = getOpenFDCount(pid) 563 println(level, 'INFO: %s (pid: %s) %s file descriptors: %i' \ 564 % (app, pid, cmd, fds), True) 565