ShaYmez/DMRlink
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

System Logger Cleanup

Browse Source 
This has gotten messy durring development, so I decided to clean it up
some. The system logger should ONLY be used for internal logging of the
program, not to try and make a "netwatch" out of (for you c-Bridge
users). Please use the log.py module for that type of thing.
This commit is contained in:
Cort Buffington 2013-11-09 11:33:52 -06:00
parent 13157cd4e2
commit 5ee94034d6
4 changed files with 115 additions and 144 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

20
bridge.py
View File

@ -13,7 +13,7 @@ from twisted.internet import task
import binascii import binascii
import dmrlink import dmrlink
from dmrlink import IPSC, UnauthIPSC, NETWORK, networks, int_id, send_to_ipsc, dmr_nat from dmrlink import IPSC, UnauthIPSC, NETWORK, networks, int_id, send_to_ipsc, dmr_nat, logger
RULES = { RULES = {
'K0USY': { 'K0USY': {
@ -123,11 +123,13 @@ class bridgeUnauthIPSC(bridgeIPSC):
def validate_auth(self, _key, _data): def validate_auth(self, _key, _data):
return True return True
for ipsc_network in NETWORK: if __name__ == '__main__':
if (NETWORK[ipsc_network]['LOCAL']['ENABLED']): logger.info('DMRlink \'bridge.py\' (c) 2013 N0MJS & the K0USY Group - SYSTEM STARTING...')
if NETWORK[ipsc_network]['LOCAL']['AUTH_ENABLED'] == True: for ipsc_network in NETWORK:
networks[ipsc_network] = bridgeIPSC(ipsc_network) if (NETWORK[ipsc_network]['LOCAL']['ENABLED']):
else: if NETWORK[ipsc_network]['LOCAL']['AUTH_ENABLED'] == True:
networks[ipsc_network] = bridgeUnauthIPSC(ipsc_network) networks[ipsc_network] = bridgeIPSC(ipsc_network)
reactor.listenUDP(NETWORK[ipsc_network]['LOCAL']['PORT'], networks[ipsc_network]) else:
reactor.run() networks[ipsc_network] = bridgeUnauthIPSC(ipsc_network)
reactor.listenUDP(NETWORK[ipsc_network]['LOCAL']['PORT'], networks[ipsc_network])
reactor.run()

180
dmrlink.py
View File

@ -59,7 +59,7 @@ try:
for row in subscribers: for row in subscribers:
subscriber_ids[int(row[1])] = (row[0]) subscriber_ids[int(row[1])] = (row[0])
except ImportError: except ImportError:
print('subscriber_ids.csv not found: Subscriber aliases will not be avaiale') logger.warning('subscriber_ids.csv not found: Subscriber aliases will not be avaiale')
try: try:
with open('./peer_ids.csv', 'rU') as peer_ids_csv: with open('./peer_ids.csv', 'rU') as peer_ids_csv:
@ -67,7 +67,7 @@ try:
for row in peers: for row in peers:
peer_ids[int(row[1])] = (row[0]) peer_ids[int(row[1])] = (row[0])
except ImportError: except ImportError:
print('peer_ids.csv not found: Peer aliases will not be avaiale') logger.warning('peer_ids.csv not found: Peer aliases will not be avaiale')
try: try:
with open('./talkgroup_ids.csv', 'rU') as talkgroup_ids_csv: with open('./talkgroup_ids.csv', 'rU') as talkgroup_ids_csv:
@ -75,107 +75,81 @@ try:
for row in talkgroups: for row in talkgroups:
talkgroup_ids[int(row[1])] = (row[0]) talkgroup_ids[int(row[1])] = (row[0])
except ImportError: except ImportError:
print('talkgroup_ids.csv not found: Talkgroup aliases will not be avaiale') logger.warning('talkgroup_ids.csv not found: Talkgroup aliases will not be avaiale')
#************************************************ #************************************************
# PARSE THE CONFIG FILE AND BUILD STRUCTURE # PARSE THE CONFIG FILE AND BUILD STRUCTURE
#************************************************ #************************************************
'''
***LINKING STATUS: Byte 6***
Byte 1 - BIT FLAGS:
xx.. .... = Peer Operational (01 only known valid value)
..xx .... = Peer MODE: 00 - No Radio, 01 - Analog, 10 - Digital
.... xx.. = IPSC Slot 1: 10 on, 01 off
.... ..xx = IPSC Slot 2: 10 on, 01 off
***SERVICE FLAGS: Bytes 7-10 (or 7-12)***
Byte 1 - 0x00 = Unknown
Byte 2 - 0x00 = Unknown
Byte 3 - BIT FLAGS:
x... .... = CSBK Message
.x.. .... = Repeater Call Monitoring
..x. .... = 3rd Party "Console" Application
...x xxxx = Unknown - default to 0
Byte 4 = BIT FLAGS:
x... .... = XNL Connected (1=true)
.x.. .... = XNL Master Device
..x. .... = XNL Slave Device
...x .... = Set if packets are authenticated
.... x... = Set if data calls are supported
.... .x.. = Set if voice calls are supported
.... ..x. = Unknown - default to 0
.... ...x = Set if master
'''
networks = {} networks = {}
NETWORK = {} NETWORK = {}
config = ConfigParser.ConfigParser() config = ConfigParser.ConfigParser()
config.read('./dmrlink.cfg') config.read('./dmrlink.cfg')
for section in config.sections(): try:
if section == 'GLOBAL': for section in config.sections():
pass if section == 'GLOBAL':
else: pass
NETWORK.update({section: {'LOCAL': {}, 'MASTER': {}, 'PEERS': []}})
NETWORK[section]['LOCAL'].update({
'MODE': '',
'PEER_OPER': True,
'PEER_MODE': 'DIGITAL',
'FLAGS': '',
'MAX_MISSED': 10,
'NUM_PEERS': 0,
'STATUS': {
'ACTIVE': False
},
'ENABLED': config.getboolean(section, 'ENABLED'),
'TS1_LINK': config.getboolean(section, 'TS1_LINK'),
'TS2_LINK': config.getboolean(section, 'TS2_LINK'),
'AUTH_ENABLED': config.getboolean(section, 'AUTH_ENABLED'),
'RADIO_ID': hex(int(config.get(section, 'RADIO_ID')))[2:].rjust(8,'0').decode('hex'),
'PORT': config.getint(section, 'PORT'),
'ALIVE_TIMER': config.getint(section, 'ALIVE_TIMER'),
'AUTH_KEY': (config.get(section, 'AUTH_KEY').rjust(40,'0')).decode('hex'),
})
NETWORK[section]['MASTER'].update({
'RADIO_ID': '\x00\x00\x00\x00',
'MODE': '\x00',
'PEER_OPER': False,
'PEER_MODE': '',
'TS1_LINK': False,
'TS2_LINK': False,
'FLAGS': '\x00\x00\x00\x00',
'STATUS': {
'CONNECTED': False,
'PEER_LIST': False,
'KEEP_ALIVES_SENT': 0,
'KEEP_ALIVES_MISSED': 0,
'KEEP_ALIVES_OUTSTANDING': 0
},
'IP': config.get(section, 'MASTER_IP'),
'PORT': config.getint(section, 'MASTER_PORT')
})
if NETWORK[section]['LOCAL']['AUTH_ENABLED']:
# 0x1C - Voice and Data calls only, 0xDC - Voice, Data and XCMP/XNL
NETWORK[section]['LOCAL']['FLAGS'] = '\x00\x00\x00\x1C'
#NETWORK[section]['LOCAL']['FLAGS'] = '\x00\x00\x00\xDC'
else: else:
NETWORK[section]['LOCAL']['FLAGS'] = '\x00\x00\x00\x0C' NETWORK.update({section: {'LOCAL': {}, 'MASTER': {}, 'PEERS': []}})
NETWORK[section]['LOCAL'].update({
'MODE': '',
'PEER_OPER': True,
'PEER_MODE': 'DIGITAL',
'FLAGS': '',
'MAX_MISSED': 10,
'NUM_PEERS': 0,
'STATUS': {
'ACTIVE': False
},
'ENABLED': config.getboolean(section, 'ENABLED'),
'TS1_LINK': config.getboolean(section, 'TS1_LINK'),
'TS2_LINK': config.getboolean(section, 'TS2_LINK'),
'AUTH_ENABLED': config.getboolean(section, 'AUTH_ENABLED'),
'RADIO_ID': hex(int(config.get(section, 'RADIO_ID')))[2:].rjust(8,'0').decode('hex'),
'PORT': config.getint(section, 'PORT'),
'ALIVE_TIMER': config.getint(section, 'ALIVE_TIMER'),
'AUTH_KEY': (config.get(section, 'AUTH_KEY').rjust(40,'0')).decode('hex'),
})
NETWORK[section]['MASTER'].update({
'RADIO_ID': '\x00\x00\x00\x00',
'MODE': '\x00',
'PEER_OPER': False,
'PEER_MODE': '',
'TS1_LINK': False,
'TS2_LINK': False,
'FLAGS': '\x00\x00\x00\x00',
'STATUS': {
'CONNECTED': False,
'PEER_LIST': False,
'KEEP_ALIVES_SENT': 0,
'KEEP_ALIVES_MISSED': 0,
'KEEP_ALIVES_OUTSTANDING': 0
},
'IP': config.get(section, 'MASTER_IP'),
'PORT': config.getint(section, 'MASTER_PORT')
})
if not NETWORK[section]['LOCAL']['TS1_LINK'] and not NETWORK[section]['LOCAL']['TS2_LINK']: if NETWORK[section]['LOCAL']['AUTH_ENABLED']:
NETWORK[section]['LOCAL']['MODE'] = '\x65' # 0x1C - Voice and Data calls only, 0xDC - Voice, Data and XCMP/XNL
elif NETWORK[section]['LOCAL']['TS1_LINK'] and not NETWORK[section]['LOCAL']['TS2_LINK']: NETWORK[section]['LOCAL']['FLAGS'] = '\x00\x00\x00\x1C'
NETWORK[section]['LOCAL']['MODE'] = '\x66' #NETWORK[section]['LOCAL']['FLAGS'] = '\x00\x00\x00\xDC'
elif not NETWORK[section]['LOCAL']['TS1_LINK'] and NETWORK[section]['LOCAL']['TS2_LINK']: else:
NETWORK[section]['LOCAL']['MODE'] = '\x69' NETWORK[section]['LOCAL']['FLAGS'] = '\x00\x00\x00\x0C'
else:
NETWORK[section]['LOCAL']['MODE'] = '\x6A'
if not NETWORK[section]['LOCAL']['TS1_LINK'] and not NETWORK[section]['LOCAL']['TS2_LINK']:
NETWORK[section]['LOCAL']['MODE'] = '\x65'
elif NETWORK[section]['LOCAL']['TS1_LINK'] and not NETWORK[section]['LOCAL']['TS2_LINK']:
NETWORK[section]['LOCAL']['MODE'] = '\x66'
elif not NETWORK[section]['LOCAL']['TS1_LINK'] and NETWORK[section]['LOCAL']['TS2_LINK']:
NETWORK[section]['LOCAL']['MODE'] = '\x69'
else:
NETWORK[section]['LOCAL']['MODE'] = '\x6A'
except:
logger.critical('Could not parse configuration file, exiting...')
sys.exit('Could not parse configuration file, exiting...')
#************************************************ #************************************************
# UTILITY FUNCTIONS FOR INTERNAL USE # UTILITY FUNCTIONS FOR INTERNAL USE
@ -189,10 +163,8 @@ def int_id(_hex_string):
# Re-Write Source Radio-ID (DMR NAT) # Re-Write Source Radio-ID (DMR NAT)
# #
def dmr_nat(_data, _nat_id): def dmr_nat(_data, _nat_id):
# _log = logger.warning
src_radio_id = _data[6:9] src_radio_id = _data[6:9]
_data = re.sub(src_radio_id, _nat_id, _data) _data = re.sub(src_radio_id, _nat_id, _data)
# _log('DMR NAT: Source %s re-written as %s', int(binascii.b2a_hex(src_radio_id), 16), int(binascii.b2a_hex(_nat_id), 16))
return _data return _data
# Lookup text data for numeric IDs # Lookup text data for numeric IDs
@ -205,23 +177,17 @@ def get_info(_id, _dict):
# Determine if the provided peer ID is valid for the provided network # Determine if the provided peer ID is valid for the provided network
# #
def valid_peer(_peer_list, _peerid): def valid_peer(_peer_list, _peerid):
# _log = logger.debug
if _peerid in _peer_list: if _peerid in _peer_list:
# _log('Peer List Has An Entry For: %s', binascii.b2a_hex(_peerid))
return True return True
# _log('Peer List Does NOT Have An Entry For: %s', binascii.b2a_hex(_peerid))
return False return False
# Determine if the provided master ID is valid for the provided network # Determine if the provided master ID is valid for the provided network
# #
def valid_master(_network, _peerid): def valid_master(_network, _peerid):
# _log = logger.warning
if NETWORK[_network]['MASTER']['RADIO_ID'] == _peerid: if NETWORK[_network]['MASTER']['RADIO_ID'] == _peerid:
# _log('Master ID is Valid: %s', binascii.b2a_hex(_peerid))
return True return True
else: else:
# _log('Master ID is NOT Valid: %s', binascii.b2a_hex(_peerid))
return False return False
@ -234,23 +200,20 @@ def send_to_ipsc(_target, _packet):
for peer in NETWORK[_target]['PEERS']: for peer in NETWORK[_target]['PEERS']:
if peer['STATUS']['CONNECTED'] == True: if peer['STATUS']['CONNECTED'] == True:
networks[_target].transport.write(_packet, (peer['IP'], peer['PORT'])) networks[_target].transport.write(_packet, (peer['IP'], peer['PORT']))
# _log(' Peer: %s', binascii.b2a_hex(peer['RADIO_ID']))
# De-register a peer from an IPSC by removing it's infomation # De-register a peer from an IPSC by removing it's infomation
# #
def de_register_peer(_network, _peerid): def de_register_peer(_network, _peerid):
# _log = logger.debug
# Iterate for the peer in our data # Iterate for the peer in our data
# _log('Peer De-Registration Requested for: %s', binascii.b2a_hex(_peerid))
for peer in NETWORK[_network]['PEERS']: for peer in NETWORK[_network]['PEERS']:
# If we find the peer, remove it (we should find it) # If we find the peer, remove it (we should find it)
if _peerid == peer['RADIO_ID']: if _peerid == peer['RADIO_ID']:
NETWORK[_network]['PEERS'].remove(peer) NETWORK[_network]['PEERS'].remove(peer)
# _log(' Peer Found And De-Registered') logger.info('(%s) Peer De-Registration Requested for: %s', _network, binascii.b2a_hex(_peerid))
return return
else: else:
# _log(' Peer NOT Found') logger.warning('(%s) Peer De-Registration Requested for: %s, but we don\'t have a listing for this peer', _network, binascii.b2a_hex(_peerid))
pass pass
@ -258,12 +221,11 @@ def de_register_peer(_network, _peerid):
# data structure in my_ipsc_config with the results, and return a simple list of peers. # data structure in my_ipsc_config with the results, and return a simple list of peers.
# #
def process_peer_list(_data, _network, _peer_list): def process_peer_list(_data, _network, _peer_list):
# _log = logger.debug
# Determine the length of the peer list for the parsing iterator # Determine the length of the peer list for the parsing iterator
_peer_list_length = int(binascii.b2a_hex(_data[5:7]), 16) _peer_list_length = int(binascii.b2a_hex(_data[5:7]), 16)
# Record the number of peers in the data structure... we'll use it later (11 bytes per peer entry) # Record the number of peers in the data structure... we'll use it later (11 bytes per peer entry)
NETWORK[_network]['LOCAL']['NUM_PEERS'] = _peer_list_length/11 NETWORK[_network]['LOCAL']['NUM_PEERS'] = _peer_list_length/11
# _log('<<- (%s) The Peer List has been Received from Master\n%s There are %s peers in this IPSC Network', _network, (' '*(len(_network)+7)), _num_peers) logger.info('(%s) Peer List Received from Master: %s peers in this IPSC', _network, _peer_list_length/11)
# Iterate each peer entry in the peer list. Skip the header, then pull the next peer, the next, etc. # Iterate each peer entry in the peer list. Skip the header, then pull the next peer, the next, etc.
for i in range(7, (_peer_list_length)+7, 11): for i in range(7, (_peer_list_length)+7, 11):
@ -420,11 +382,11 @@ class IPSC(DatagramProtocol):
self.PEER_REG_REPLY_PKT = (PEER_REG_REPLY + self._local_id + IPSC_VER) self.PEER_REG_REPLY_PKT = (PEER_REG_REPLY + self._local_id + IPSC_VER)
self.PEER_ALIVE_REQ_PKT = (PEER_ALIVE_REQ + self._local_id + self.TS_FLAGS) self.PEER_ALIVE_REQ_PKT = (PEER_ALIVE_REQ + self._local_id + self.TS_FLAGS)
self.PEER_ALIVE_REPLY_PKT = (PEER_ALIVE_REPLY + self._local_id + self.TS_FLAGS) self.PEER_ALIVE_REPLY_PKT = (PEER_ALIVE_REPLY + self._local_id + self.TS_FLAGS)
logger.info('(%s) IPSC Instance Created', self._network)
else: else:
# If we didn't get called correctly, log it! # If we didn't get called correctly, log it!
# #
logger.error('(%s) Unexpected arguments found.', self._network) logger.error('(%s) IPSC Instance Could Not be Created... Exiting', self._network)
sys.exit() sys.exit()
@ -499,14 +461,11 @@ class IPSC(DatagramProtocol):
# Remove the hash from a packet and return the payload # Remove the hash from a packet and return the payload
# #
def strip_hash(self, _data): def strip_hash(self, _data):
# _log = logger.debug
# _log('Stripped Packet: %s', binascii.b2a_hex(_data[:-10]))
return _data[:-10] return _data[:-10]
# Take a RECEIVED packet, calculate the auth hash and verify authenticity # Take a RECEIVED packet, calculate the auth hash and verify authenticity
# #
def validate_auth(self, _key, _data): def validate_auth(self, _key, _data):
_log = logger.info
_payload = self.strip_hash(_data) _payload = self.strip_hash(_data)
_hash = _data[-10:] _hash = _data[-10:]
_chk_hash = binascii.a2b_hex((hmac.new(_key,_payload,hashlib.sha1)).hexdigest()[:20]) _chk_hash = binascii.a2b_hex((hmac.new(_key,_payload,hashlib.sha1)).hexdigest()[:20])
@ -514,7 +473,6 @@ class IPSC(DatagramProtocol):
if _chk_hash == _hash: if _chk_hash == _hash:
return True return True
else: else:
_log('AUTHENTICATION FAILURE: \n\t Payload: %s\n\t Hash: %s', binascii.b2a_hex(_payload), binascii.b2a_hex(_hash))
return False return False
@ -526,6 +484,7 @@ class IPSC(DatagramProtocol):
# Right now, without this, we really dont' know anything is happening. # Right now, without this, we really dont' know anything is happening.
# print_master(self._network) # print_master(self._network)
# print_peer_list(self._network) # print_peer_list(self._network)
logger.debug('(%s) Periodic Connection Maintenance Loop Started', self._network)
pass pass
def maintenance_loop(self): def maintenance_loop(self):
@ -596,7 +555,7 @@ class IPSC(DatagramProtocol):
peer['STATUS']['CONNECTED'] = False peer['STATUS']['CONNECTED'] = False
self._peer_list.remove(peer['RADIO_ID']) # Remove the peer from the simple list FIRST self._peer_list.remove(peer['RADIO_ID']) # Remove the peer from the simple list FIRST
self._peers.remove(peer) # Becuase once it's out of the dictionary, you can't use it for anything else. self._peers.remove(peer) # Becuase once it's out of the dictionary, you can't use it for anything else.
logger.error('Maximum Peer Keep-Alives Missed -- De-registering the Peer: %s', peer) logger.warning('(%s) Maximum Peer Keep-Alives Missed -- De-registering the Peer: %s', self._network, peer)
# Update our stats before moving on... # Update our stats before moving on...
peer['STATUS']['KEEP_ALIVES_SENT'] += 1 peer['STATUS']['KEEP_ALIVES_SENT'] += 1
@ -811,6 +770,7 @@ class UnauthIPSC(IPSC):
#************************************************ #************************************************
if __name__ == '__main__': if __name__ == '__main__':
logger.info('DMRlink \'dmrlink.py\' (c) 2013 N0MJS & the K0USY Group - SYSTEM STARTING...')
networks = {} networks = {}
for ipsc_network in NETWORK: for ipsc_network in NETWORK:
if (NETWORK[ipsc_network]['LOCAL']['ENABLED']): if (NETWORK[ipsc_network]['LOCAL']['ENABLED']):

30
ipsc/ipsc_logger.py
View File

@ -11,6 +11,9 @@
from logging.config import dictConfig from logging.config import dictConfig
import logging import logging
# Full path/name of the log file:
_log_file_name = '/tmp/dmrlink.log'
dictConfig({ dictConfig({
'version': 1, 'version': 1,
'disable_existing_loggers': False, 'disable_existing_loggers': False,
@ -33,31 +36,36 @@ dictConfig({
'class': 'logging.StreamHandler', 'class': 'logging.StreamHandler',
'formatter': 'simple' 'formatter': 'simple'
}, },
'file': {
'level': 'DEBUG',
'class': 'logging.FileHandler',
'formatter': 'simple',
'filename': '/tmp/ipsc.log',
},
'console-timed': { 'console-timed': {
'level': 'DEBUG', 'level': 'DEBUG',
'class': 'logging.StreamHandler', 'class': 'logging.StreamHandler',
'formatter': 'timed' 'formatter': 'timed'
}, },
'file': {
'level': 'DEBUG',
'class': 'logging.FileHandler',
'formatter': 'simple',
'filename': _log_file_name,
},
'file-timed': { 'file-timed': {
'level': 'DEBUG', 'level': 'DEBUG',
'class': 'logging.FileHandler', 'class': 'logging.FileHandler',
'formatter': 'timed', 'formatter': 'timed',
'filename': '/tmp/ipsc.log', 'filename': _log_file_name,
}, },
'syslog': {
'level': 'INFO',
'class': 'logging.handlers.SysLogHandler',
'formatter': 'verbose',
}
}, },
'loggers': { 'loggers': {
'ipsc': { 'dmrlink': {
# 'handlers': ['file-timed', 'console-timed'], 'handlers': ['file-timed', 'syslog'],
'handlers': ['file', 'console'], # 'handlers': ['file', 'console'],
'level': 'INFO', 'level': 'INFO',
'propagate': True, 'propagate': True,
} }
} }
}) })
logger = logging.getLogger('ipsc') logger = logging.getLogger('dmrlink')

21
log.py
View File

@ -15,7 +15,7 @@ import struct
import time import time
import binascii import binascii
import dmrlink import dmrlink
from dmrlink import IPSC, UnauthIPSC, NETWORK, networks, get_info, int_id, subscriber_ids, peer_ids, talkgroup_ids from dmrlink import IPSC, UnauthIPSC, NETWORK, networks, get_info, int_id, subscriber_ids, peer_ids, talkgroup_ids, logger
class logIPSC(IPSC): class logIPSC(IPSC):
@ -111,12 +111,13 @@ class logUnauthIPSC(logIPSC):
# #
def validate_auth(self, _key, _data): def validate_auth(self, _key, _data):
return True return True
if __name__ == '__main__':
for ipsc_network in NETWORK: logger.info('DMRlink \'log.py\' (c) 2013 N0MJS & the K0USY Group - SYSTEM STARTING...')
if (NETWORK[ipsc_network]['LOCAL']['ENABLED']): for ipsc_network in NETWORK:
if NETWORK[ipsc_network]['LOCAL']['AUTH_ENABLED'] == True: if (NETWORK[ipsc_network]['LOCAL']['ENABLED']):
networks[ipsc_network] = logIPSC(ipsc_network) if NETWORK[ipsc_network]['LOCAL']['AUTH_ENABLED'] == True:
else: networks[ipsc_network] = logIPSC(ipsc_network)
networks[ipsc_network] = logUnauthIPSC(ipsc_network) else:
reactor.listenUDP(NETWORK[ipsc_network]['LOCAL']['PORT'], networks[ipsc_network]) networks[ipsc_network] = logUnauthIPSC(ipsc_network)
reactor.run() reactor.listenUDP(NETWORK[ipsc_network]['LOCAL']['PORT'], networks[ipsc_network])
reactor.run()