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