import argparse
import os
import sys
import syslog
import subprocess
import glob
import fnmatch
import textwrap
import datetime
import time
import signal
import re
import platform
_version_ = '1.0.0'
node_name = ''
linux_release = ''
tipc_srcver = ''
basedir = '/sys/kernel/debug'
trace_dir = '/sys/kernel/debug/tracing'
trace_pid = '/var/run/tipc-trace.pid'
tipcutils = '/etc/tipcutils'
trace_data = tipcutils + '/tipc-trace.dat'
args=[]
trace_info = {'tipc_l2_device_event' : 'Trace L2 device or TIPC bearer events (e.g. DEV_UP, DEV_DOWN, MTU_CHANGE, etc.)',
'tipc_link_bc_ack' : 'Trace broadcast acknowledgments on the TIPC link broadcast transmit queue',
'tipc_link_dump' : 'Dump TIPC link data (e.g. link state, queues, etc.) in case of failures (e.g. retransmission failure)',
'tipc_link_conges' : 'Trace if TIPC link transmit and backlog queues are full',
'tipc_link_fsm' : 'Trace TIPC link finite state machine and events (e.g. ESTABLISHED -> RESET)',
'tipc_link_reset' : 'Trace if TIPC link is reset due to any reasons (e.g. link lost, deleted, etc.)',
'tipc_link_retrans' : 'Trace the retransmission requests from peer if any, along with the current link transmit queue status',
'tipc_link_timeout' : 'Trace the regular TIPC link timer timeout',
'tipc_link_too_silent' : 'Trace if a link is "too silent", that means there is no probe reply or traffic from peer for a while',
'tipc_list_dump' : 'Dump TIPC list or queues in case of failures',
'tipc_node_check_state' : 'Trace for the tipc_node_check_state()',
'tipc_node_create' : 'Trace if a TIPC node is created',
'tipc_node_delete' : 'Trace if a TIPC node is deleted',
'tipc_node_dump' : 'Dump TIPC node data in case of failures',
'tipc_node_fsm' : 'Trace TIPC node finite state machine and events (e.g. SELF_UP_PEER_UP -> SELF_DOWN_PEER_LEAVING)',
'tipc_node_link_down' : 'Trace if TIPC link is down from node layer',
'tipc_node_link_up' : 'Trace if TIPC link is up from node layer',
'tipc_node_lost_contact': 'Trace if TIPC node contact is lost',
'tipc_node_reset_links' : 'Trace if TIPC reset all links to peer (e.g. at retranmission failure)',
'tipc_node_timeout' : 'Trace the regular TIPC node timer timeout',
'tipc_proto_build' : 'Trace when a PROTOCOL message is built for sending',
'tipc_proto_rcv' : 'Trace when a PROTOCOL message is received',
'tipc_sk_advance_rx' : 'Trace when a message is released from the socket receive queue',
'tipc_sk_create' : 'Trace when a TIPC socket is created',
'tipc_sk_drop_msg' : 'Trace if a message is dropped due to any reasons (e.g. no port)',
'tipc_sk_dump' : 'Dump TIPC socket data in case of failures (e.g. TIPC_ERR_OVERLOAD)',
'tipc_sk_poll' : 'Trace when user makes a poll() on TIPC socket',
'tipc_sk_tx_conges' : 'Trace if TX flow is congested at TIPC socket message sending',
'tipc_sk_filter_rcv' : 'Trace when a message is to be enqueued in the socket receive queue',
'tipc_sk_overlimit1' : 'Trace if socket receive and backlog queue are about to be overloaded (> 90% allocated)',
'tipc_sk_overlimit2' : 'Trace if socket receive queue is about to be overloaded (> 90% allocated)',
'tipc_sk_rej_msg' : 'Trace if a socket message is rejected due to any reasons (e.g. invalid)',
'tipc_sk_release' : 'Trace when a TIPC socket is released',
'tipc_sk_sendmcast' : 'Trace when user sends a mcast message through TIPC socket',
'tipc_sk_sendmsg' : 'Trace when user sends a RDM or DGRAM message through TIPC socket',
'tipc_sk_sendstream' : 'Trace when user sends a stream-oriented data message through TIPC socket',
'tipc_sk_shutdown' : 'Trace when a TIPC socket is shutdown',
'tipc_skb_dump' : 'Dump skb or TIPC message data in case of failures',
}
trace_events = []
trace_groups = {'gdump' : ['Group of the dump events for failure cases', ],
'glink' : ['Group of the traces for TIPC link object', ],
'gsock' : ['Group of the traces for TIPC socket object', ],
'gnode' : ['Group of the traces for TIPC node object', ],
}
trace_suites = {'s1':
[
'Tracing suite for link lost issues: consists of enabling the link_fsm trace, also in case of link "too silent", the traces for PROTOCOL messages are triggered automatically',
'',
[
'tipc_link_fsm',
'1',
'',
[]
],
[
'tipc_link_too_silent',
'1',
'',
['enable_event:tipc:tipc_proto_rcv', 'enable_event:tipc:tipc_proto_build']
]
],
's2':
[
'Tracing suite for socket overload issues: looks for socket receive queue overlimited (> 90% allocated), then enables the traces on the socket advancing, dump, etc.',
'',
[
'tipc_sk_overlimit2',
'1',
'',
['enable_event:tipc:tipc_sk_advance_rx', 'enable_event:tipc:tipc_sk_dump']
]
],
}
interpreter_fmts = {
'state': ['STATE_MSG, [4]->[5]: [9]',
'sess seqno ack seq_gap snd_nxt bc_ack bc_gap bc_snxt probe stopbit hsz dsz',
'(12) (6) (7) (14) (13) (8) (16) (15) (10) (11) (2) (3)'],
'reset': ['RESET_MSG, [4]->[5]: [9]',
'sess seqno ack seq_gap snd_nxt bc_ack bc_gap bc_snxt probe stopbit hsz dsz',
'(12) (6) (7) (14) (13) (8) (16) (15) (10) (11) (2) (3)'],
'activate': ['ACTIVATE_MSG, [4]->[5]: [9]',
'sess seqno ack seq_gap snd_nxt bc_ack bc_gap bc_snxt probe stopbit hsz dsz',
'(12) (6) (7) (14) (13) (8) (16) (15) (10) (11) (2) (3)'],
'conn': ['CONN_MSG, [9]->[10]',
'imp srcdrop dstdrop errcode reroute seqno ack bc_ack hsz dsz',
'(0) (11) (12) (13) (14) (6) (7) (8) (2) (3)'],
'mcast': ['MCAST_MSG, [4]:[9]->[5]:[10]',
'imp type lower upper srcdrop dstdrop errcode reroute seqno ack bc_ack hsz dsz',
'(0) (11) (12) (13) (14) (15) (16) (17) (6) (7) (8) (2) (3)'],
'named': ['NAMED_MSG, [4]:[9]->[5]:[10]',
'imp type inst srcdrop dstdrop errcode reroute seqno ack bc_ack hsz dsz',
'(0) (11) (12) (13) (14) (15) (16) (6) (7) (8) (2) (3)'],
'direct': ['DIRECT_MSG, [4]:[9]->[5]:[10]',
'imp srcdrop dstdrop errcode reroute seqno ack bc_ack hsz dsz',
'(0) (11) (12) (13) (14) (6) (7) (8) (2) (3)'],
'bcast': ['BCAST_PROTOCOL, [4]->[5]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'bundle': ['BUNDLER_MSG, [4]->[5]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'connmg': ['CONN_MANAGER, [4]:[9]->[5]:[10]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'group': ['GROUP_PROTOCOL, [4]->[5]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'tunnel': ['TUNNEL_PROTOCOL, [4]->[5]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'namedist': ['NAME_DISTRIBUTOR, [4]->[5]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'frag': ['MSG_FRAGMENTER, [4]->[5]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'lconfig': ['LINK_CONFIG, [4]->[5]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'skwakeup': ['SOCK_WAKEUP, [4]:[9]->[5]:[10]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'topsrv': ['TOP_SRV, [4]->[5]',
'type seqno ack bcack hsz dsz',
'(1) (6) (7) (8) (2) (3)'],
'skb': ['dev len dlen hlen truesz cloned sk nrfrags swtime hwtime',
'(0) (1) (2) (3) (4) (5) (6) (7) (8) (9)'],
'skb_cb': '',
'skb_cb_v1': ['bytes omem nxtretr valid chimp ackers',
'(0) (1) (2) (3) (4) (5)'],
'skb_cb_v2': ['bytes nxtretr valid wakeup chsz chimp ackers',
'(0) (1) (2) (3) (4) (5) (6)'],
'link_data': '',
'link_data_v1': ['transq: |[16]-[17]|[15], deferq: |[19]-[20]|[18], backlq: |[22]-[23]|[21], inputq: |[25]-[26]|[24]',
'addr state silent rst_cnt in_sess sess p_sess sndnsta rcvnsta sndnxt rcvnxt pcaps pfrom stale acked',
'(0) (1) (10) (11) (2) (3) (4) (7) (8) (5) (6) (9) (12) (13) (14)'],
'link_data_v2': ['transq: |[16]-[17]|[15], deferq: |[19]-[20]|[18], backlq: |[22]-[23]|[21], inputq: |[25]-[26]|[24]',
'addr state silent rst_cnt in_sess sess p_sess sndnsta rcvnsta sndnxt rcvnxt pcaps lretran stale acked',
'(0) (1) (10) (11) (2) (3) (4) (7) (8) (5) (6) (9) (12) (13) (14)'],
'node_data': ['addr state slot0 slot1 actfg fosent syncp linkcnt wolinks caps keepalv',
'(0) (1) (2) (3) (4) (5) (6) (7) (8) (9) (10)'],
'sk_data_1': '',
'sk_data_1_v1': ['NO-CONNECTED, NO-PUBLISHED, [2]:[3]',
'sndq: [15]/[16], rcvq: [17]/[18], bklq: [19]',
'sktype skstate sndwin rcvwin maxpkt pcaps conglk sntnack rcvnack duplcnt shutdwn',
'(0) (1) (6) (7) (8) (9) (10) (11) (12) (13) (14)'],
'sk_data_1_v2': ['NO-CONNECTED, NO-PUBLISHED, [2]:[3]',
'sndq: [16]/[17], rcvq: [18]/[19], bklq: [20]',
'sktype skstate sndwin rcvwin maxpkt pcaps conglk sntnack rcvnack duplcnt recnt recong',
'(0) (1) (6) (7) (8) (9) (10) (11) (12) (13) (14) (15)'],
'sk_data_2': '',
'sk_data_2_v1': ['CONNECTED: {{[7],[8]}}, [2]:[3]<->[5]:[6]',
'sndq: [19]/[20], rcvq: [21]/[22], bklq: [23]',
'sktype skstate sndwin rcvwin maxpkt pcaps conglk sntnack rcvnack duplcnt shutdwn',
'(0) (1) (10) (11) (12) (13) (14) (15) (16) (17) (18)'],
'sk_data_2_v2': ['CONNECTED: {{[7],[8]}}, [2]:[3]<->[5]:[6]',
'sndq: [20]/[21], rcvq: [22]/[23], bklq: [24]',
'sktype skstate sndwin rcvwin maxpkt pcaps conglk sntnack rcvnack duplcnt recnt recong',
'(0) (1) (10) (11) (12) (13) (14) (15) (16) (17) (18) (19)'],
'sk_data_3': '',
'sk_data_3_v1': ['PUBLISHED: {{[6],[7],[8]}}, [2]:[3]',
'sndq: [18]/[19], rcvq: [20]/[21], bklq: [22]',
'sktype skstate sndwin rcvwin maxpkt pcaps conglk sntnack rcvnack duplcnt shutdwn',
'(0) (1) (9) (10) (11) (12) (13) (14) (15) (16) (17)'],
'sk_data_3_v2': ['PUBLISHED: {{[6],[7],[8]}}, [2]:[3]',
'sndq: [19]/[20], rcvq: [21]/[22], bklq: [23]',
'sktype skstate sndwin rcvwin maxpkt pcaps conglk sntnack rcvnack duplcnt recnt recong',
'(0) (1) (9) (10) (11) (12) (13) (14) (15) (16) (17) (18)'],
}
trace_regexes = [
'(?P<header>: tipc_[0-9a-z_]+: |: tracing_mark_write: )',
'(?P<state>msg: 7 0 )',
'(?P<reset>msg: 7 1 )',
'(?P<activate>msg: 7 2 )',
'(?P<conn>msg: [0123] 0 )',
'(?P<mcast>msg: [0123] 1 )',
'(?P<named>msg: [0123] 2 )',
'(?P<direct>msg: [0123] 3 )',
'(?P<bcast>msg: 5 )',
'(?P<bundle>msg: 6 )',
'(?P<connmg>msg: 8 )',
'(?P<group>msg: 9 )',
'(?P<tunnel>msg: 10 )',
'(?P<namedist>msg: 11 )',
'(?P<frag>msg: 12 )',
'(?P<lconfig>msg: 13 )',
'(?P<skwakeup>msg: 14 )',
'(?P<topsrv>msg: 15 )',
'(?P<skb>skb: )',
'(?P<skb_cb>cb\[\]: )',
'(?P<link_data>link data: \d)',
'(?P<node_data>node data: \d)',
'(?P<sk_data_1>sk data: \d.* \| 0 \| 0 \| )',
'(?P<sk_data_2>sk data: \d.* \| 1 .* \| 0 \| )',
'(?P<sk_data_3>sk data: \d.* \| 0 \| 1 .* \| )',
'(?P<suppressed>transmq: len = 0|backlogq: <0 0 0 0 0>, len = 0|deferdq: len = 0|inputq: len = 0|wakeup: len = 0|sk_write_queue: len = 0|sk_receive_queue: len = 0| mtu: 0| media: UNKNOWN)',
'(?P<others>transmq: |backlogq: |deferdq: |inputq: |wakeup: |sk_write_queue: |sk_receive_queue: | mtu: | media: |msg: |link data: |node data: |sk data: )',
]
interpreter_rc = re.compile(r'|'.join(trace_regexes))
states_dict = {
'e' : 'EST-ED',
'e0' : 'EST-ING',
'100' : 'RST',
'2000' : 'RST-ING',
'd0000' : 'P-RST',
'f00000' : 'FLO-ING',
'c000000' : 'SYN-ING',
'dd' : 'DWN-DWN',
'aa' : 'UP-UP',
'd1' : 'DWN-LEV',
'ac' : 'UP-COM',
'ca' : 'COM-UP',
'1d' : 'LEV-DWN',
'f0' : 'FLO-ING',
'cc' : 'SYN-ING',
}
fdebug = False
quiet_output = False
def log_debug(debug_msg):
if fdebug:
print('DEBUG | ' + debug_msg)
def log_error(err_msg):
err_msg = 'ERROR | ' + err_msg
syslog.syslog(syslog.LOG_ERR, err_msg)
if quiet_output == False:
print(err_msg)
def log_info(info_msg):
info_msg = 'INFO | ' + info_msg
syslog.syslog(syslog.LOG_INFO, info_msg)
if quiet_output == False:
print(info_msg)
def read(file, mode = 'r'):
try:
with open(file, mode) as f:
return f.read().rstrip()
except IOError as e:
log_debug('read(): file \'{0}\', mode \'{1}\', error ({2})- {3}'.format(file, mode, e.errno, e.strerror))
return ''
def write(file, data, mode = 'w'):
try:
with open(file, mode) as f:
f.write(data)
return True
except IOError as e:
log_debug('write(): file \'{0}\', data \'{1}\', mode \'{2}\', error ({3})- {4}'.format(file, data, mode, e.errno, e.strerror))
return False
def multireplace(text, wordDic):
if not text or not wordDic:
return text
rc = re.compile('|'.join(map(re.escape, wordDic)))
def translate(match):
return wordDic[match.group(0)]
return rc.sub(translate, text)
def mark_trace(reason):
write(trace_dir + '/trace_marker', reason + ' at {0}'.format(datetime.datetime.now()))
def switch_trace(sts):
write(trace_dir + '/tracing_on', sts)
def read_sts(evt):
sts = read(evt + '/enable')
return sts
def read_filter(evt):
filter = read(evt + '/filter')
if 'none' in filter or 'parse_error' in filter or 'Error' in filter:
filter = ''
return filter
def read_triggers(evt):
triggers = read(evt + '/trigger')
if '# Available triggers' in triggers:
triggers = []
else:
triggers = multireplace(triggers, {':unlimited': '', ':count=': ':'})
triggers = triggers.split('\n')
return triggers
def parse_args():
global args
global fdebug
parser = argparse.ArgumentParser(description='TIPC tracing tool, ver {0}'.format(_version_), formatter_class=argparse.RawDescriptionHelpFormatter,
usage='''
\t%(prog)s -hlxraspc
\t%(prog)s -e IDX [IDX ...] [-f FILTER] [-t TRIGGER [TRIGGER ...]]
\t%(prog)s -d IDY [IDY ...] [-f FILTER] [-t TRIGGER [TRIGGER ...]]
\t%(prog)s -k SK_FILTER
\t%(prog)s -u ID [--desc DESC]
\t%(prog)s -a [-i] [-o OUTPUT]
\t%(prog)s -i -o OUTPUT
''',
epilog=textwrap.dedent('''\
Samples:
o tipc-trace -e all Enable all the TIPC traces
o tipc-trace -e 5 tipc_link_dump gnode s2
Enable trace id '5', trace name 'tipc_link_dump', trace
group 'gnode' and trace suite 's2'
See 'tipc-trace -l' for more details about the trace ID,
name, group or suite
o tipc-trace -e tipc_link_timeout -f 'name ~ "*1001002:data0*"'
Enable the 'tipc_link_timeout' trace and set the filter
for the trace, so that there is only the timeout event
of the link towards node '1001002' on bearer 'data0' to
be outputed
o tipc-trace -e tipc_link_too_silent -t 'enable_event:tipc:tipc_proto_rcv'
Enable the 'tipc_link_too_silent' trace and set the
trigger for the trace, so that when the event happens,
it will trigger (enable) the 'tipc_proto_rcv' trace as
well
o tipc-trace -e s2 Enable trace suite 's2' (trace events and filters,
triggers will be set as built-in suite configurations).
A FILTER or TRIGGER if any has no effect with the trace
suite enabling/disabling
o tipc-trace -d gsock -f '0'
Disable all the traces in group 'gsock' and clear their
filter if any
o tipc-trace -d tipc_link_too_silent -t '!enable_event:tipc:tipc_proto_rcv'
Disable the 'tipc_link_too_silent' trace and clear the
trigger
o tipc-trace -k '11111 0 0 0 0'
Set the filter for all the socket traces, so only the
socket with port id 11111 will be traced
o tipc-trace -k '0 1 2222 33 44'
Set the filter for all the socket traces, so only the
STREAM socket(s) which publishes the service {2222, 33-
44} or connects to the service will be traced
o tipc-trace -u s9 --desc 'my trace suite'
Save the current trace configurations as a trace suite:
id - 's9' and description - 'my trace suite'
o tipc-trace -a Start the traces and output to the screen (try <ctrl-c>
to terminate the traces)
o tipc-trace -ao '/my/path/trace.out'
Start the traces and output to '/my/path/trace.out'
o tipc-trace -ai Start the traces and interpret the outputs to screen
o tipc-trace -io '/my/path/trace.out'
Interpret the trace outputs from '/my/path/trace.out' to
'/my/path/trace.out.interpreted' (i.e. the same file but
with '.interpreted')
o tipc-trace -s Stop the traces
'''))
group1 = parser.add_argument_group('Print')
group1.add_argument('-l', '--list', dest='list', action='store_true', help='List all available TIPC traces, test suites')
group1.add_argument('-x', '--status', dest='status', action='store_true', help='Show the current trace status')
group1.add_argument('--debug', dest='debug', action='store_true', help=argparse.SUPPRESS)
group2 = parser.add_argument_group('Configure')
group2.add_argument('-e', '--enable', dest='idx', nargs='+', help='Enable one or more TIPC traces')
group2.add_argument('-d', '--disable', dest='idy', nargs='+', help='Disable one or more TIPC traces')
group2.add_argument('-f', '--filter', dest='filter', default='', help='''Set or clear the filter command for the traces specified by \'-e\' or \'-d\' option.
Note: FILTER must follow a correct format for the particular traces, a \'0\' will clear the traces filter, see samples below!''')
group2.add_argument('-t', '--trigger', dest='trigger', default=[], nargs='+', help='''Set or clear the trigger command(s) for the traces specified by \'-e\' or \'-d\' option.
Note: TRIGGER must follow a correct format for the particular traces, a !TRIGGER will clear the particular trace trigger, see samples below''')
group2.add_argument('-k', '--sk_filter', dest='sk_filter', help='''Set a filter for all the socket traces, the SK_FILTER is a tuple of (port_id, sock_type, name_type, name_lower, name_upper)
which will determine what socket to be traced, see samples below!''')
group2.add_argument('-r', '--reset', dest='reset', action='store_true', help='Disable all the traces, clear all the filters and triggers')
group2.add_argument('-u', '--suite', dest='id', help='Save the current trace configurations as a trace suite, see samples below')
group2.add_argument('--desc', dest='desc', default=' ', help='Describe the trace suite made via \'-n\' option')
group3 = parser.add_argument_group('Trace')
group3.add_argument('-a', '--start', dest='start', action='store_true', help='Start the traces, output to the file specified by \'-o\' option, otherwise screen')
group3.add_argument('-p', '--suspend', dest='suspend', action='store_true', help='Suspend the traces')
group3.add_argument('-c', '--continue', dest='cont', action='store_true', help='Continue the traces')
group3.add_argument('-s', '--stop', dest='stop', action='store_true', help='Stop the traces')
group3.add_argument('-o', '--output', dest='output', default='screen' , help='Specify the trace output file (default: screen)')
group3.add_argument('-i', '--interpret', dest='interpret', action='store_true', help='Interpret the trace outputs, either online (with \'-a\') or offline (with \'-o\'), see samples below!')
if not len(sys.argv) > 1:
parser.print_help()
sys.exit(0)
args = parser.parse_args()
fdebug = args.debug
if (args.filter or args.trigger) and not (args.idx or args.idy):
parser.error('too few argument, -e/--enable or -d/--disable required!')
if (args.output != 'screen') and not (args.start or args.interpret):
parser.error('too few argument, -a/--start or -i/--interpret option required!')
if args.sk_filter and not all(c.isdigit() or c.isspace() for c in args.sk_filter):
parser.error('invalid socket filter tuple!')
if args.interpret and not (args.start or (args.output != 'screen')):
parser.error('too few argument, -a/--start option or -o/--output required!')
if (args.desc != ' ') and not args.id:
parser.error('too few argument, -u/--suite option required!')
log_debug('parse_args(): \'{0}\''.format(args))
def init_trace():
global node_name
global linux_release
global tipc_srcver
global trace_dir
global trace_events
global trace_groups
global trace_suites
try:
node_name = platform.node()
linux_release = platform.system() + ' ' + platform.release()
tipc_srcver = subprocess.check_output('modinfo tipc | grep srcversion', shell=True).rstrip().lstrip('srcversion: ')
except:
log_info('Oops, cannot obtain node or TIPC info!')
log_debug('init_trace(): error {0}'.format(sys.exc_info()[1]))
return False
if not os.path.exists(basedir):
cmd = 'mount -t debugfs ' + basedir
try:
subprocess.check_call(cmd, shell=True)
except subprocess.CalledProcessError as e:
log_error('Failed to mount debugfs: \'{0}\', returned {1}'.format(cmd, e.returncode))
return False
trace_dir = basedir + '/tracing'
tipc_dir = trace_dir + '/events/tipc'
if not os.path.exists(tipc_dir):
log_info('Oops, there is no TIPC trace avaiable!')
return False
if not os.path.exists(tipcutils):
os.mkdir(tipcutils, 755)
trace_events = sorted(glob.glob(tipc_dir + '/tipc_*'))
trace_groups['gdump'].extend(fnmatch.filter(trace_events, '*tipc_*_dump*'))
trace_groups['glink'].extend(fnmatch.filter(trace_events, '*tipc_link*'))
trace_groups['gsock'].extend(fnmatch.filter(trace_events, '*tipc_sk_*'))
trace_groups['gnode'].extend(fnmatch.filter(trace_events, '*tipc_node*'))
if os.path.isfile(trace_data):
try:
trace_suites = eval(read(trace_data, 'r+b'))
log_debug('init_trace(): trace_suites \'{0}\''.format(trace_suites))
except:
log_error('Failed to read trace data, error {0}'.format(sys.exc_info()[1]))
return False
return True
def list_trace():
eventfmt = '{:16s}{:32s}{:s}'
print('TIPC trace events:')
print(eventfmt.format('Event ID', 'Event Name', 'Event Description'))
for idx, evt in enumerate(trace_events, start=1):
evt_name = evt.split('/')[-1]
print(eventfmt.format(str(idx), evt_name, trace_info.get(evt_name, '(unknown)')))
groupfmt = '{:16s}{:s}'
print('\nTIPC trace groups:')
print(groupfmt.format('Group ID', 'Group Description'))
for group, group_entry in trace_groups.iteritems():
print(groupfmt.format(group, group_entry[0]))
suitefmt = '{:16s}{:s}'
print('\nTIPC trace suites:')
print(suitefmt.format('Suite ID', 'Suite Description'))
wrapper = textwrap.TextWrapper()
wrapper.subsequent_indent = '\t\t'
for suite, suite_entry in trace_suites.iteritems():
print(suitefmt.format(suite, wrapper.fill(suite_entry[0])))
def check_trace():
stsfmt = '{:16s}{:32s}{:16s}{:64s}{:s}'
print("TIPC trace status:")
print(stsfmt.format('Event ID', 'Event Name', 'Status', 'Filter', 'Trigger'))
for id, evt in enumerate(trace_events, start=1):
s = read_sts(evt)
s = multireplace(s, {'0':'Disabled', '1':'Enabled'})
f = read_filter(evt)
if not f:
f = 'none'
t = read_triggers(evt)
if not t:
t = 'none'
else:
t = ('\n'+' '*128).join(t)
print(stsfmt.format(str(id), evt.split('/')[-1], s, f, t))
skffmt = '{:16s}{:16s}{:16s}{:16s}{:s}'
print("\nTIPC socket trace filter:")
print(skffmt.format('Socket ID', 'Socket Type', 'Name Type', 'Name Lower', 'Name Upper'))
sk_filter = read('/proc/sys/net/tipc/sk_filter').split()
print(skffmt.format(*sk_filter))
tracing_sts = read(trace_dir + '/tracing_on')
tracing_sts = multireplace(tracing_sts, {'0':'off', '1': 'on'})
if os.path.isfile(trace_pid):
tipc_sts = 'running'
else:
tipc_sts = 'not running'
print('\nTIPC trace: {0}, tracing: {1}'.format(tipc_sts, tracing_sts))
def apply_trace(evt, sts, filter = '', triggers = []):
rc = 0
if not write(evt + '/enable', sts):
rc = rc | 1
if filter:
old_filter = read_filter(evt)
if not old_filter:
old_filter = '0'
if not write(evt + '/filter', filter):
write(evt + '/filter', old_filter)
rc = rc | 2
for trigger in triggers:
if not write(evt + '/trigger', trigger):
rc = rc | 4
log_debug('apply_trace(): evt \'{0}\' sts \'{1}\', filter \'{2}\', triggers \'{3}\', rc \'{4}\''.format(evt.split('/')[-1], sts, filter, triggers, rc))
return rc
def setup_trace(ids, sts, filter = '', triggers = []):
if 'all' in ids:
ids = map(str, range(1, len(trace_events) + 1))
for id in ids:
rc = -1
if sts == '0':
print('Disabling trace \'{0}\'...'.format(id)),
elif sts == '1':
print('Enabling trace \'{0}\'...'.format(id)),
if id.isdigit():
i = int(id)
if (i > 0 and i <= len(trace_events)):
evt = trace_events[i-1]
rc = apply_trace(evt, sts, filter, triggers)
else:
evt = trace_dir + '/events/tipc/' + id
if evt in trace_events:
rc = apply_trace(evt, sts, filter, triggers)
elif id in trace_groups:
rc = 0
for evt in trace_groups[id][1:]:
rc |= apply_trace(evt, sts, filter, triggers)
elif id in trace_suites:
rc = 0
uskfilter = trace_suites[id][1]
if uskfilter:
if sts == '0':
uskfilter = '0 0 0 0 0'
write('/proc/sys/net/tipc/sk_filter', uskfilter)
for trace in trace_suites[id][2:]:
uevt = trace_dir + '/events/tipc/' + trace[0]
usts = trace[1]
ufilter = trace[2]
utriggers = trace[3]
if sts == '0':
if usts == '1':
usts = '0'
if ufilter:
ufilter = '0'
if utriggers:
utriggers = ['!' + t for t in utriggers]
rc |= apply_trace(uevt, usts, ufilter, utriggers)
if rc == 0:
print('done!')
elif rc == -1:
print('unknown!')
else:
print('partially done, return code <{0}>: invalid filter/trigger command (or filter command already existed)!'.format(rc))
def save_trace(id, desc):
global trace_suites
if id in trace_suites:
overwrite = raw_input('Trace suite \'{0}\' already existed, do you want to overwrite it? (Y/n): '.format(id))
if overwrite == 'Y':
trace_suites[id] = []
else:
return
print('Saving traces...'),
trace_suites[id] = [desc]
skfilter = read('/proc/sys/net/tipc/sk_filter').replace('\t', ' ')
if skfilter == '0 0 0 0 0':
skfilter = ''
trace_suites[id] += [skfilter]
for evt in trace_events:
sts = read_sts(evt)
filter = read_filter(evt)
triggers = read_triggers(evt)
if sts[0] == '1' or filter or triggers:
evt = evt.split('/')[-1]
trace_suites[id] += [[evt, sts[0], filter, triggers]]
write(trace_data, str(trace_suites), 'w+b')
log_debug('save_trace(): trace_suites \'{0}\''.format(trace_suites))
print('done!')
return
def set_skfilter(sk_filter):
if write('/proc/sys/net/tipc/sk_filter', sk_filter):
print('Setting socket filter... done!')
else:
print('Setting socket filter... failed!')
def reset_trace():
print('Resetting all traces...'),
write(trace_dir + '/events/tipc/filter', '0')
for evt in trace_events:
triggers = read_triggers(evt)
for trigger in triggers:
write(evt + '/trigger', '!' + trigger)
write(trace_dir + '/events/tipc/enable', '0')
write('/proc/sys/net/tipc/sk_filter', '0 0 0 0 0')
print('done!')
def hook_pipe(output, interpreter):
if (output != 'screen') and os.fork():
return
write(trace_pid, str(os.getpid()))
pipein = open(trace_dir + '/trace_pipe', 'r')
if output == 'screen':
pipeout = sys.stdout
else:
pipeout = open(output, 'a')
signal.signal(signal.SIGINT, terminate_trace)
signal.signal(signal.SIGHUP, terminate_trace)
try:
while True:
line = pipein.readline()
if line:
if interpreter:
line = interpret_line(line)
pipeout.write(line)
else:
time.sleep(.5)
except SystemExit:
log_debug('hook_pipe(): SystemExit - okay!')
except:
log_error('Exception during hook_pipe(): error {0}'.format(sys.exc_info()[1]))
pipein.close()
if output != 'screen':
pipeout.close()
os.remove(trace_pid)
sys.exit(0)
def start_trace(output, interpreter):
if os.path.isfile(trace_pid):
print('TIPC trace: already started?!')
return False
switch_trace('1')
mark_trace('Tracing started on ' + node_name + ' (' + linux_release + ', tipc ' + tipc_srcver + ')')
print('TIPC trace: started!')
hook_pipe(output, interpreter)
return True
def stop_trace():
if not os.path.isfile(trace_pid):
print('TIPC trace: already stopped or not started yet?!')
return False
mark_trace('Tracing stopped')
switch_trace('0')
pid = int(read(trace_pid))
try:
os.kill(pid, signal.SIGINT)
except OSError:
log_error('Failed at os.kill(): pid {0}, error {1}'.format(pid, sys.exc_info()[1]))
os.remove(trace_pid)
print('TIPC trace: stopped!')
return True
def terminate_trace(signum, frame):
if read(trace_dir + '/tracing_on') == '1':
mark_trace('Tracing terminated')
switch_trace('0')
print('\nTIPC trace: terminated!')
log_debug('terminate_trace(): SIG#{0}!'.format(signum))
sys.exit(0)
def suspend_trace():
mark_trace('Tracing suspended')
switch_trace('0')
print('TIPC trace: suspended!')
def continue_trace():
switch_trace('1')
mark_trace('Tracing continued')
print('TIPC trace: continued!')
def interpret_line(line, width = 8):
indent = width * 3
match = interpreter_rc.search(line)
if match:
key = match.lastgroup
try:
if key == 'suppressed':
line = ''
elif key == 'header':
hdrfmt = '{0[3]:{i}}{0[1]:{w}}{0[2]:{w}}{0[0]}\n{0[4]:{i}}{1}'
line = hdrfmt.format(line.split(), line[match.end():], i=indent, w=width)
elif key == 'others':
line = line[:match.end()-1].ljust(indent) + line[match.end():].lstrip()
elif (key in interpreter_fmts) and interpreter_fmts[key]:
offset = line.index(': ') + 2
data = line[offset:].rstrip().replace(' | ', ' ').split() + ['n/a']*10
if (key == 'link_data' or key == 'node_data') and (data[1] in states_dict):
data[1] = states_dict[data[1]]
data_fmt = interpreter_fmts[key].format(data, i=' '*indent)
line = line[:offset].ljust(indent) + data_fmt
except KeyboardInterrupt:
raise
except:
log_debug('interpret_line(): line \'{0}\', error {1}, from key \'{2}\'\nmatch dict \'{3}\''.format(line.rstrip(), sys.exc_info()[1], key, match.groupdict()))
return line
def interpret_file(input):
output = input + '.interpreted'
t1 = time.time()
c = 0
print('Interpreter: '),
try:
with open(output, 'w') as o:
with open(input, 'r') as i:
while True:
t2 = time.time()
c = (c + 1) % 10000
if c == 0:
sys.stdout.write('.')
sys.stdout.flush()
line = i.readline()
if line:
o.write(interpret_line(line))
else:
break
except KeyboardInterrupt:
print('partially done (~ {0:.3}s)!\nOutput: \'{1}\'!'.format(t2-t1, output))
return
except:
print('failed, error {0}!'.format(sys.exc_info()[1]))
return
print('done (~ {0:.3}s)!\nOutput: \'{1}\'!'.format(t2-t1, output))
return
def compile_fmts(ver, width = 8):
global interpreter_fmts
repl_rules1 = {'[': '{0[', ']': ']}'}
repl_rules2 = {' ': '', '(': '{0[', ')': ']:{w}.{p}}}'.format(w=width, p=width-1)}
for key, fmt in interpreter_fmts.items():
if not fmt:
continue
interpreter_fmt = ''
for line in fmt:
if '[' in line:
line_fmt = multireplace(line, repl_rules1)
elif '(' in line:
line_fmt = multireplace(line, repl_rules2)
else:
hdrs = line.split()
line_fmt = ('{:{w}.{p}}' * len(hdrs)).format(*hdrs, w=width, p=width-1)
interpreter_fmt = interpreter_fmt + line_fmt + '\n{i}'
interpreter_fmts[key] = interpreter_fmt.rstrip('{i}')
for key, fmt in interpreter_fmts.items():
if ver in key:
skey = key.replace(ver, '')
if skey in interpreter_fmts:
interpreter_fmts[skey] = fmt
else:
log_debug('compile_fmts(): skey {0}, ver {1}, key {2}'.format(skey, ver, key))
def decide_ver(output = ''):
if output:
try:
_linux = subprocess.check_output('grep -os \'Linux.*, tipc\' ' + output, shell=True)
except:
log_debug('decide_ver(): error {0}'.format(sys.exc_info()[1]))
log_info('Failed to retrieve kernel/TIPC version, some traces might not be interpreted!')
return '_v?'
else:
_linux = linux_release
if 'Linux 4.20.' in _linux:
return '_v1'
if 'Linux 4.4.' in _linux:
return '_v2'
log_info('Unknown kernel/TIPC version, some traces might not be interpreted!')
return '_v?'
if __name__== "__main__":
parse_args()
if not init_trace():
sys.exit(1)
if args.list:
list_trace()
if args.idx:
setup_trace(args.idx, '1', args.filter, args.trigger)
if args.idy:
setup_trace(args.idy, '0', args.filter, args.trigger)
if args.sk_filter:
set_skfilter(args.sk_filter)
if args.reset:
reset_trace()
if args.status:
check_trace()
if args.id:
save_trace(args.id, args.desc)
if args.start:
if args.interpret:
ver = decide_ver()
compile_fmts(ver)
start_trace(args.output, args.interpret)
if args.stop:
stop_trace()
if args.suspend:
suspend_trace()
if args.cont:
continue_trace()
if args.interpret and (args.output != 'screen') and not args.start:
ver = decide_ver(args.output)
compile_fmts(ver)
interpret_file(args.output)
sys.exit(0)