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

modified logging methodology 

configure a logger in each module, create the proper configuration in the __main__ of each file
This commit is contained in:
Cort Buffington 2018-11-24 10:20:47 -06:00
parent c5f2811a45
commit 71e794dd52
5 changed files with 217 additions and 225 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

47
hb_bridge_all.py
View File

@ -45,13 +45,18 @@ from twisted.protocols.basic import NetstringReceiver
from twisted.internet import reactor, task
# Things we import from the main hblink module
from hblink import HBSYSTEM, OPENBRIDGE, systems, hblink_handler, reportFactory, REPORT_OPCODES, config_reports
from hblink import HBSYSTEM, OPENBRIDGE, systems, hblink_handler, reportFactory, REPORT_OPCODES, config_reports, mk_aliases
from dmr_utils.utils import hex_str_3, int_id, get_alias
from dmr_utils import decode, bptc, const
import hb_config
import hb_log
import hb_const
# The module needs logging logging, but handlers, etc. are controlled by the parent
import logging
logger = logging.getLogger(__name__)
# Does anybody read this stuff? There's a PEP somewhere that says I should do this.
__author__ = 'Cortney T. Buffington, N0MJS'
__copyright__ = 'Copyright (c) 2016-2018 Cortney T. Buffington, N0MJS and the K0USY Group'
@ -66,8 +71,8 @@ __status__ = 'pre-alpha'
class bridgeallSYSTEM(HBSYSTEM):
def __init__(self, _name, _config, _logger, _report):
HBSYSTEM.__init__(self, _name, _config, _logger, _report)
def __init__(self, _name, _config, _report):
HBSYSTEM.__init__(self, _name, _config, _report)
# Status information for the system, TS1 & TS2
# 1 & 2 are "timeslot"
@ -228,42 +233,20 @@ if __name__ == '__main__':
# Set up the signal handler
def sig_handler(_signal, _frame):
logger.info('SHUTDOWN: HBROUTER IS TERMINATING WITH SIGNAL %s', str(_signal))
hblink_handler(_signal, _frame, logger)
hblink_handler(_signal, _frame)
logger.info('SHUTDOWN: ALL SYSTEM HANDLERS EXECUTED - STOPPING REACTOR')
reactor.stop()
# Set signal handers so that we can gracefully exit if need be
for sig in [signal.SIGTERM, signal.SIGINT]:
signal.signal(sig, sig_handler)
# ID ALIAS CREATION
# Download
if CONFIG['ALIASES']['TRY_DOWNLOAD'] == True:
# Try updating peer aliases file
result = try_download(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['PEER_FILE'], CONFIG['ALIASES']['PEER_URL'], CONFIG['ALIASES']['STALE_TIME'])
logger.info(result)
# Try updating subscriber aliases file
result = try_download(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['SUBSCRIBER_FILE'], CONFIG['ALIASES']['SUBSCRIBER_URL'], CONFIG['ALIASES']['STALE_TIME'])
logger.info(result)
# Make Dictionaries
peer_ids = mk_id_dict(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['PEER_FILE'])
if peer_ids:
logger.info('ID ALIAS MAPPER: peer_ids dictionary is available')
subscriber_ids = mk_id_dict(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['SUBSCRIBER_FILE'])
if subscriber_ids:
logger.info('ID ALIAS MAPPER: subscriber_ids dictionary is available')
talkgroup_ids = mk_id_dict(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['TGID_FILE'])
if talkgroup_ids:
logger.info('ID ALIAS MAPPER: talkgroup_ids dictionary is available')
# Create the name-number mapping dictionaries
peer_ids, subscriber_ids, talkgroup_ids = mk_aliases(CONFIG)
# INITIALIZE THE REPORTING LOOP
report_server = config_reports(CONFIG, logger, reportFactory)
report_server = config_reports(CONFIG, reportFactory)
# HBlink instance creation
logger.info('HBlink \'HBlink.py\' (c) 2016-2018 N0MJS & the K0USY Group - SYSTEM STARTING...')
for system in CONFIG['SYSTEMS']:
@ -272,7 +255,7 @@ if __name__ == '__main__':
logger.critical('%s FATAL: Instance is mode \'OPENBRIDGE\', \n\t\t...Which would be tragic for Bridge All, since it carries multiple call\n\t\tstreams simultaneously. hb_bridge_all.py onlyl works with MMDVM-based systems', system)
sys.exit('hb_bridge_all.py cannot function with systems that are not MMDVM devices. System {} is configured as an OPENBRIDGE'.format(system))
else:
systems[system] = HBSYSTEM(system, CONFIG, logger, report_server)
systems[system] = HBSYSTEM(system, CONFIG, report_server)
reactor.listenUDP(CONFIG['SYSTEMS'][system]['PORT'], systems[system], interface=CONFIG['SYSTEMS'][system]['IP'])
logger.debug('%s instance created: %s, %s', CONFIG['SYSTEMS'][system]['MODE'], system, systems[system])

135
hb_confbridge.py
View File

@ -45,7 +45,7 @@ from twisted.protocols.basic import NetstringReceiver
from twisted.internet import reactor, task
# Things we import from the main hblink module
from hblink import HBSYSTEM, OPENBRIDGE, systems, hblink_handler, reportFactory, REPORT_OPCODES
from hblink import HBSYSTEM, OPENBRIDGE, systems, hblink_handler, reportFactory, REPORT_OPCODES, mk_aliases
from dmr_utils.utils import hex_str_3, int_id, get_alias
from dmr_utils import decode, bptc, const
import hb_config
@ -55,6 +55,11 @@ import hb_const
# Stuff for socket reporting
import cPickle as pickle
# The module needs logging logging, but handlers, etc. are controlled by the parent
import logging
logger = logging.getLogger(__name__)
# Does anybody read this stuff? There's a PEP somewhere that says I should do this.
__author__ = 'Cortney T. Buffington, N0MJS'
__copyright__ = 'Copyright (c) 2016-2018 Cortney T. Buffington, N0MJS and the K0USY Group'
@ -68,20 +73,20 @@ __email__ = 'n0mjs@me.com'
# Timed loop used for reporting HBP status
#
# REPORT BASED ON THE TYPE SELECTED IN THE MAIN CONFIG FILE
def config_reports(_config, _logger, _factory):
def config_reports(_config, _factory):
if True: #_config['REPORTS']['REPORT']:
def reporting_loop(_logger, _server):
_logger.debug('Periodic reporting loop started')
def reporting_loop(logger, _server):
logger.debug('Periodic reporting loop started')
_server.send_config()
_server.send_bridge()
_logger.info('HBlink TCP reporting server configured')
logger.info('HBlink TCP reporting server configured')
report_server = _factory(_config, _logger)
report_server = _factory(_config)
report_server.clients = []
reactor.listenTCP(_config['REPORTS']['REPORT_PORT'], report_server)
reporting = task.LoopingCall(reporting_loop, _logger, report_server)
reporting = task.LoopingCall(reporting_loop, logger, report_server)
reporting.start(_config['REPORTS']['REPORT_INTERVAL'])
return report_server
@ -186,8 +191,8 @@ def stream_trimmer_loop():
class routerOBP(OPENBRIDGE):
def __init__(self, _name, _config, _logger, _report):
OPENBRIDGE.__init__(self, _name, _config, _logger, _report)
def __init__(self, _name, _config, _report):
OPENBRIDGE.__init__(self, _name, _config, _report)
self.STATUS = {}
@ -218,7 +223,7 @@ class routerOBP(OPENBRIDGE):
self.STATUS[_stream_id]['LC'] = const.LC_OPT + _dst_id + _rf_src
self._logger.info('(%s) *CALL START* STREAM ID: %s SUB: %s (%s) PEER: %s (%s) TGID %s (%s), TS %s', \
logger.info('(%s) *CALL START* STREAM ID: %s SUB: %s (%s) PEER: %s (%s) TGID %s (%s), TS %s', \
self._system, int_id(_stream_id), get_alias(_rf_src, subscriber_ids), int_id(_rf_src), get_alias(_peer_id, peer_ids), int_id(_peer_id), get_alias(_dst_id, talkgroup_ids), int_id(_dst_id), _slot)
if CONFIG['REPORTS']['REPORT']:
self._report.send_bridgeEvent('GROUP VOICE,START,{},{},{},{},{},{}'.format(self._system, int_id(_stream_id), int_id(_peer_id), int_id(_rf_src), _slot, int_id(_dst_id)))
@ -250,18 +255,18 @@ class routerOBP(OPENBRIDGE):
if _frame_type == hb_const.HBPF_DATA_SYNC and _dtype_vseq == hb_const.HBPF_SLT_VHEAD:
decoded = decode.voice_head_term(dmrpkt)
_target_status[_stream_id]['LC'] = decoded['LC']
self._logger.debug('(%s) Created LC for OpenBridge destination: System: %s, TGID: %s', self._system, _target['SYSTEM'], int_id(_target['TGID']))
logger.debug('(%s) Created LC for OpenBridge destination: System: %s, TGID: %s', self._system, _target['SYSTEM'], int_id(_target['TGID']))
# If we don't have a voice header then don't wait to decode the Embedded LC
# just make a new one from the HBP header. This is good enough, and it saves lots of time
else:
_target_status[_stream_id]['LC'] = const.LC_OPT + _dst_id + _rf_src
self._logger.info('(%s) Created LC with *LATE ENTRY* for OpenBridge destination: System: %s, TGID: %s', self._system, _target['SYSTEM'], int_id(_target['TGID']))
logger.info('(%s) Created LC with *LATE ENTRY* for OpenBridge destination: System: %s, TGID: %s', self._system, _target['SYSTEM'], int_id(_target['TGID']))
_target_status[_stream_id]['H_LC'] = bptc.encode_header_lc(_target_status[_stream_id]['LC'])
_target_status[_stream_id]['T_LC'] = bptc.encode_terminator_lc(_target_status[_stream_id]['LC'])
_target_status[_stream_id]['EMB_LC'] = bptc.encode_emblc(_target_status[_stream_id]['LC'])
self._logger.info('(%s) Conference Bridge: %s, Call Bridged to OBP System: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
logger.info('(%s) Conference Bridge: %s, Call Bridged to OBP System: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
# Record the time of this packet so we can later identify a stale stream
_target_status[_stream_id]['LAST'] = pkt_time
@ -301,22 +306,22 @@ class routerOBP(OPENBRIDGE):
if ((_target['TGID'] != _target_status[_target['TS']]['RX_TGID']) and ((pkt_time - _target_status[_target['TS']]['RX_TIME']) < _target_system['GROUP_HANGTIME'])):
if self.STATUS[_stream_id]['CONTENTION'] == False:
self.STATUS[_stream_id]['CONTENTION'] = True
self._logger.info('(%s) Call not routed to TGID %s, target active or in group hangtime: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['RX_TGID']))
logger.info('(%s) Call not routed to TGID %s, target active or in group hangtime: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['RX_TGID']))
continue
if ((_target['TGID'] != _target_status[_target['TS']]['TX_TGID']) and ((pkt_time - _target_status[_target['TS']]['TX_TIME']) < _target_system['GROUP_HANGTIME'])):
if self.STATUS[_stream_id]['CONTENTION'] == False:
self.STATUS[_stream_id]['CONTENTION'] = True
self._logger.info('(%s) Call not routed to TGID%s, target in group hangtime: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['TX_TGID']))
logger.info('(%s) Call not routed to TGID%s, target in group hangtime: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['TX_TGID']))
continue
if (_target['TGID'] == _target_status[_target['TS']]['RX_TGID']) and ((pkt_time - _target_status[_target['TS']]['RX_TIME']) < hb_const.STREAM_TO):
if self.STATUS[_stream_id]['CONTENTION'] == False:
self.STATUS[_stream_id]['CONTENTION'] = True
self._logger.info('(%s) Call not routed to TGID%s, matching call already active on target: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['RX_TGID']))
logger.info('(%s) Call not routed to TGID%s, matching call already active on target: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['RX_TGID']))
continue
if (_target['TGID'] == _target_status[_target['TS']]['TX_TGID']) and (_rf_src != _target_status[_target['TS']]['TX_RFS']) and ((pkt_time - _target_status[_target['TS']]['TX_TIME']) < hb_const.STREAM_TO):
if self.STATUS[_stream_id]['CONTENTION'] == False:
self.STATUS[_stream_id]['CONTENTION'] = True
self._logger.info('(%s) Call not routed for subscriber %s, call route in progress on target: HBSystem: %s, TS: %s, TGID: %s, SUB: %s', self._system, int_id(_rf_src), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['TX_TGID']), int_id(_target_status[_target['TS']]['TX_RFS']))
logger.info('(%s) Call not routed for subscriber %s, call route in progress on target: HBSystem: %s, TS: %s, TGID: %s, SUB: %s', self._system, int_id(_rf_src), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['TX_TGID']), int_id(_target_status[_target['TS']]['TX_RFS']))
continue
# Is this a new call stream?
@ -332,8 +337,8 @@ class routerOBP(OPENBRIDGE):
_target_status[_target['TS']]['TX_H_LC'] = bptc.encode_header_lc(dst_lc)
_target_status[_target['TS']]['TX_T_LC'] = bptc.encode_terminator_lc(dst_lc)
_target_status[_target['TS']]['TX_EMB_LC'] = bptc.encode_emblc(dst_lc)
self._logger.debug('(%s) Generating TX FULL and EMB LCs for HomeBrew destination: System: %s, TS: %s, TGID: %s', self._system, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
self._logger.info('(%s) Conference Bridge: %s, Call Bridged to HBP System: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
logger.debug('(%s) Generating TX FULL and EMB LCs for HomeBrew destination: System: %s, TS: %s, TGID: %s', self._system, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
logger.info('(%s) Conference Bridge: %s, Call Bridged to HBP System: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
# Set other values for the contention handler to test next time there is a frame to forward
_target_status[_target['TS']]['TX_TIME'] = pkt_time
@ -366,26 +371,26 @@ class routerOBP(OPENBRIDGE):
# Transmit the packet to the destination system
systems[_target['SYSTEM']].send_system(_tmp_data)
#self._logger.debug('(%s) Packet routed by bridge: %s to system: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
#logger.debug('(%s) Packet routed by bridge: %s to system: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
# Final actions - Is this a voice terminator?
if (_frame_type == hb_const.HBPF_DATA_SYNC) and (_dtype_vseq == hb_const.HBPF_SLT_VTERM):
call_duration = pkt_time - self.STATUS[_stream_id]['START']
self._logger.info('(%s) *CALL END* STREAM ID: %s SUB: %s (%s) PEER: %s (%s) TGID %s (%s), TS %s, Duration: %s', \
logger.info('(%s) *CALL END* STREAM ID: %s SUB: %s (%s) PEER: %s (%s) TGID %s (%s), TS %s, Duration: %s', \
self._system, int_id(_stream_id), get_alias(_rf_src, subscriber_ids), int_id(_rf_src), get_alias(_peer_id, peer_ids), int_id(_peer_id), get_alias(_dst_id, talkgroup_ids), int_id(_dst_id), _slot, call_duration)
if CONFIG['REPORTS']['REPORT']:
self._report.send_bridgeEvent('GROUP VOICE,END,{},{},{},{},{},{},{:.2f}'.format(self._system, int_id(_stream_id), int_id(_peer_id), int_id(_rf_src), _slot, int_id(_dst_id), call_duration))
removed = self.STATUS.pop(_stream_id)
self._logger.debug('(%s) OpenBridge sourced call stream end, remove terminated Stream ID: %s', self._system, int_id(_stream_id))
logger.debug('(%s) OpenBridge sourced call stream end, remove terminated Stream ID: %s', self._system, int_id(_stream_id))
if not removed:
self_logger.error('(%s) *CALL END* STREAM ID: %s NOT IN LIST -- THIS IS A REAL PROBLEM', self._system, int_id(_stream_id))
selflogger.error('(%s) *CALL END* STREAM ID: %s NOT IN LIST -- THIS IS A REAL PROBLEM', self._system, int_id(_stream_id))
class routerHBP(HBSYSTEM):
def __init__(self, _name, _config, _logger, _report):
HBSYSTEM.__init__(self, _name, _config, _logger, _report)
def __init__(self, _name, _config, _report):
HBSYSTEM.__init__(self, _name, _config, _report)
# Status information for the system, TS1 & TS2
# 1 & 2 are "timeslot"
@ -449,12 +454,12 @@ class routerHBP(HBSYSTEM):
# Is this a new call stream?
if (_stream_id != self.STATUS[_slot]['RX_STREAM_ID']):
if (self.STATUS[_slot]['RX_TYPE'] != hb_const.HBPF_SLT_VTERM) and (pkt_time < (self.STATUS[_slot]['RX_TIME'] + hb_const.STREAM_TO)) and (_rf_src != self.STATUS[_slot]['RX_RFS']):
self._logger.warning('(%s) Packet received with STREAM ID: %s <FROM> SUB: %s PEER: %s <TO> TGID %s, SLOT %s collided with existing call', self._system, int_id(_stream_id), int_id(_rf_src), int_id(_peer_id), int_id(_dst_id), _slot)
logger.warning('(%s) Packet received with STREAM ID: %s <FROM> SUB: %s PEER: %s <TO> TGID %s, SLOT %s collided with existing call', self._system, int_id(_stream_id), int_id(_rf_src), int_id(_peer_id), int_id(_dst_id), _slot)
return
# This is a new call stream
self.STATUS[_slot]['RX_START'] = pkt_time
self._logger.info('(%s) *CALL START* STREAM ID: %s SUB: %s (%s) PEER: %s (%s) TGID %s (%s), TS %s', \
logger.info('(%s) *CALL START* STREAM ID: %s SUB: %s (%s) PEER: %s (%s) TGID %s (%s), TS %s', \
self._system, int_id(_stream_id), get_alias(_rf_src, subscriber_ids), int_id(_rf_src), get_alias(_peer_id, peer_ids), int_id(_peer_id), get_alias(_dst_id, talkgroup_ids), int_id(_dst_id), _slot)
if CONFIG['REPORTS']['REPORT']:
self._report.send_bridgeEvent('GROUP VOICE,START,{},{},{},{},{},{}'.format(self._system, int_id(_stream_id), int_id(_peer_id), int_id(_rf_src), _slot, int_id(_dst_id)))
@ -494,18 +499,18 @@ class routerHBP(HBSYSTEM):
if _frame_type == hb_const.HBPF_DATA_SYNC and _dtype_vseq == hb_const.HBPF_SLT_VHEAD:
decoded = decode.voice_head_term(dmrpkt)
_target_status[_stream_id]['LC'] = decoded['LC']
self._logger.debug('(%s) Created LC for OpenBridge destination: System: %s, TGID: %s', self._system, _target['SYSTEM'], int_id(_target['TGID']))
logger.debug('(%s) Created LC for OpenBridge destination: System: %s, TGID: %s', self._system, _target['SYSTEM'], int_id(_target['TGID']))
# If we don't have a voice header then don't wait to decode the Embedded LC
# just make a new one from the HBP header. This is good enough, and it saves lots of time
else:
_target_status[_stream_id]['LC'] = const.LC_OPT + _dst_id + _rf_src
self._logger.info('(%s) Created LC with *LATE ENTRY* for OpenBridge destination: System: %s, TGID: %s', self._system, _target['SYSTEM'], int_id(_target['TGID']))
logger.info('(%s) Created LC with *LATE ENTRY* for OpenBridge destination: System: %s, TGID: %s', self._system, _target['SYSTEM'], int_id(_target['TGID']))
_target_status[_stream_id]['H_LC'] = bptc.encode_header_lc(_target_status[_stream_id]['LC'])
_target_status[_stream_id]['T_LC'] = bptc.encode_terminator_lc(_target_status[_stream_id]['LC'])
_target_status[_stream_id]['EMB_LC'] = bptc.encode_emblc(_target_status[_stream_id]['LC'])
self._logger.info('(%s) Conference Bridge: %s, Call Bridged to OBP System: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
logger.info('(%s) Conference Bridge: %s, Call Bridged to OBP System: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
# Record the time of this packet so we can later identify a stale stream
_target_status[_stream_id]['LAST'] = pkt_time
@ -544,19 +549,19 @@ class routerHBP(HBSYSTEM):
#
if ((_target['TGID'] != _target_status[_target['TS']]['RX_TGID']) and ((pkt_time - _target_status[_target['TS']]['RX_TIME']) < _target_system['GROUP_HANGTIME'])):
if _frame_type == hb_const.HBPF_DATA_SYNC and _dtype_vseq == hb_const.HBPF_SLT_VHEAD and self.STATUS[_slot]['RX_STREAM_ID'] != _seq:
self._logger.info('(%s) Call not routed to TGID %s, target active or in group hangtime: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['RX_TGID']))
logger.info('(%s) Call not routed to TGID %s, target active or in group hangtime: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['RX_TGID']))
continue
if ((_target['TGID'] != _target_status[_target['TS']]['TX_TGID']) and ((pkt_time - _target_status[_target['TS']]['TX_TIME']) < _target_system['GROUP_HANGTIME'])):
if _frame_type == hb_const.HBPF_DATA_SYNC and _dtype_vseq == hb_const.HBPF_SLT_VHEAD and self.STATUS[_slot]['RX_STREAM_ID'] != _seq:
self._logger.info('(%s) Call not routed to TGID%s, target in group hangtime: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['TX_TGID']))
logger.info('(%s) Call not routed to TGID%s, target in group hangtime: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['TX_TGID']))
continue
if (_target['TGID'] == _target_status[_target['TS']]['RX_TGID']) and ((pkt_time - _target_status[_target['TS']]['RX_TIME']) < hb_const.STREAM_TO):
if _frame_type == hb_const.HBPF_DATA_SYNC and _dtype_vseq == hb_const.HBPF_SLT_VHEAD and self.STATUS[_slot]['RX_STREAM_ID'] != _seq:
self._logger.info('(%s) Call not routed to TGID%s, matching call already active on target: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['RX_TGID']))
logger.info('(%s) Call not routed to TGID%s, matching call already active on target: HBSystem: %s, TS: %s, TGID: %s', self._system, int_id(_target['TGID']), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['RX_TGID']))
continue
if (_target['TGID'] == _target_status[_target['TS']]['TX_TGID']) and (_rf_src != _target_status[_target['TS']]['TX_RFS']) and ((pkt_time - _target_status[_target['TS']]['TX_TIME']) < hb_const.STREAM_TO):
if _frame_type == hb_const.HBPF_DATA_SYNC and _dtype_vseq == hb_const.HBPF_SLT_VHEAD and self.STATUS[_slot]['RX_STREAM_ID'] != _seq:
self._logger.info('(%s) Call not routed for subscriber %s, call route in progress on target: HBSystem: %s, TS: %s, TGID: %s, SUB: %s', self._system, int_id(_rf_src), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['TX_TGID']), int_id(_target_status[_target['TS']]['TX_RFS']))
logger.info('(%s) Call not routed for subscriber %s, call route in progress on target: HBSystem: %s, TS: %s, TGID: %s, SUB: %s', self._system, int_id(_rf_src), _target['SYSTEM'], _target['TS'], int_id(_target_status[_target['TS']]['TX_TGID']), int_id(_target_status[_target['TS']]['TX_RFS']))
continue
# Is this a new call stream?
@ -571,8 +576,8 @@ class routerHBP(HBSYSTEM):
_target_status[_target['TS']]['TX_H_LC'] = bptc.encode_header_lc(dst_lc)
_target_status[_target['TS']]['TX_T_LC'] = bptc.encode_terminator_lc(dst_lc)
_target_status[_target['TS']]['TX_EMB_LC'] = bptc.encode_emblc(dst_lc)
self._logger.debug('(%s) Generating TX FULL and EMB LCs for HomeBrew destination: System: %s, TS: %s, TGID: %s', self._system, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
self._logger.info('(%s) Conference Bridge: %s, Call Bridged to HBP System: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
logger.debug('(%s) Generating TX FULL and EMB LCs for HomeBrew destination: System: %s, TS: %s, TGID: %s', self._system, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
logger.info('(%s) Conference Bridge: %s, Call Bridged to HBP System: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
# Set other values for the contention handler to test next time there is a frame to forward
_target_status[_target['TS']]['TX_TIME'] = pkt_time
@ -605,14 +610,14 @@ class routerHBP(HBSYSTEM):
# Transmit the packet to the destination system
systems[_target['SYSTEM']].send_system(_tmp_data)
#self._logger.debug('(%s) Packet routed by bridge: %s to system: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
#logger.debug('(%s) Packet routed by bridge: %s to system: %s TS: %s, TGID: %s', self._system, _bridge, _target['SYSTEM'], _target['TS'], int_id(_target['TGID']))
# Final actions - Is this a voice terminator?
if (_frame_type == hb_const.HBPF_DATA_SYNC) and (_dtype_vseq == hb_const.HBPF_SLT_VTERM) and (self.STATUS[_slot]['RX_TYPE'] != hb_const.HBPF_SLT_VTERM):
call_duration = pkt_time - self.STATUS[_slot]['RX_START']
self._logger.info('(%s) *CALL END* STREAM ID: %s SUB: %s (%s) PEER: %s (%s) TGID %s (%s), TS %s, Duration: %s', \
logger.info('(%s) *CALL END* STREAM ID: %s SUB: %s (%s) PEER: %s (%s) TGID %s (%s), TS %s, Duration: %s', \
self._system, int_id(_stream_id), get_alias(_rf_src, subscriber_ids), int_id(_rf_src), get_alias(_peer_id, peer_ids), int_id(_peer_id), get_alias(_dst_id, talkgroup_ids), int_id(_dst_id), _slot, call_duration)
if CONFIG['REPORTS']['REPORT']:
self._report.send_bridgeEvent('GROUP VOICE,END,{},{},{},{},{},{},{:.2f}'.format(self._system, int_id(_stream_id), int_id(_peer_id), int_id(_rf_src), _slot, int_id(_dst_id), call_duration))
@ -630,7 +635,7 @@ class routerHBP(HBSYSTEM):
# TGID matches a rule source, reset its timer
if _slot == _system['TS'] and _dst_id == _system['TGID'] and ((_system['TO_TYPE'] == 'ON' and (_system['ACTIVE'] == True)) or (_system['TO_TYPE'] == 'OFF' and _system['ACTIVE'] == False)):
_system['TIMER'] = pkt_time + _system['TIMEOUT']
self._logger.info('(%s) Transmission match for Bridge: %s. Reset timeout to %s', self._system, _bridge, _system['TIMER'])
logger.info('(%s) Transmission match for Bridge: %s. Reset timeout to %s', self._system, _bridge, _system['TIMER'])
# TGID matches an ACTIVATION trigger
if (_dst_id in _system['ON'] or _dst_id in _system['RESET']) and _slot == _system['TS']:
@ -639,15 +644,15 @@ class routerHBP(HBSYSTEM):
if _system['ACTIVE'] == False:
_system['ACTIVE'] = True
_system['TIMER'] = pkt_time + _system['TIMEOUT']
self._logger.info('(%s) Bridge: %s, connection changed to state: %s', self._system, _bridge, _system['ACTIVE'])
logger.info('(%s) Bridge: %s, connection changed to state: %s', self._system, _bridge, _system['ACTIVE'])
# Cancel the timer if we've enabled an "OFF" type timeout
if _system['TO_TYPE'] == 'OFF':
_system['TIMER'] = pkt_time
self._logger.info('(%s) Bridge: %s set to "OFF" with an on timer rule: timeout timer cancelled', self._system, _bridge)
logger.info('(%s) Bridge: %s set to "OFF" with an on timer rule: timeout timer cancelled', self._system, _bridge)
# Reset the timer for the rule
if _system['ACTIVE'] == True and _system['TO_TYPE'] == 'ON':
_system['TIMER'] = pkt_time + _system['TIMEOUT']
self._logger.info('(%s) Bridge: %s, timeout timer reset to: %s', self._system, _bridge, _system['TIMER'] - pkt_time)
logger.info('(%s) Bridge: %s, timeout timer reset to: %s', self._system, _bridge, _system['TIMER'] - pkt_time)
# TGID matches an DE-ACTIVATION trigger
if (_dst_id in _system['OFF'] or _dst_id in _system['RESET']) and _slot == _system['TS']:
@ -655,19 +660,19 @@ class routerHBP(HBSYSTEM):
if _dst_id in _system['OFF']:
if _system['ACTIVE'] == True:
_system['ACTIVE'] = False
self._logger.info('(%s) Bridge: %s, connection changed to state: %s', self._system, _bridge, _system['ACTIVE'])
logger.info('(%s) Bridge: %s, connection changed to state: %s', self._system, _bridge, _system['ACTIVE'])
# Cancel the timer if we've enabled an "ON" type timeout
if _system['TO_TYPE'] == 'ON':
_system['TIMER'] = pkt_time
self._logger.info('(%s) Bridge: %s set to ON with and "OFF" timer rule: timeout timer cancelled', self._system, _bridge)
logger.info('(%s) Bridge: %s set to ON with and "OFF" timer rule: timeout timer cancelled', self._system, _bridge)
# Reset the timer for the rule
if _system['ACTIVE'] == False and _system['TO_TYPE'] == 'OFF':
_system['TIMER'] = pkt_time + _system['TIMEOUT']
self._logger.info('(%s) Bridge: %s, timeout timer reset to: %s', self._system, _bridge, _system['TIMER'] - pkt_time)
logger.info('(%s) Bridge: %s, timeout timer reset to: %s', self._system, _bridge, _system['TIMER'] - pkt_time)
# Cancel the timer if we've enabled an "ON" type timeout
if _system['ACTIVE'] == True and _system['TO_TYPE'] == 'ON' and _dst_group in _system['OFF']:
_system['TIMER'] = pkt_time
self._logger.info('(%s) Bridge: %s set to ON with and "OFF" timer rule: timeout timer cancelled', self._system, _bridge)
logger.info('(%s) Bridge: %s set to ON with and "OFF" timer rule: timeout timer cancelled', self._system, _bridge)
#
# END IN-BAND SIGNALLING
@ -705,7 +710,6 @@ if __name__ == '__main__':
import sys
import os
import signal
from dmr_utils.utils import try_download, mk_id_dict
# Change the current directory to the location of the application
os.chdir(os.path.dirname(os.path.realpath(sys.argv[0])))
@ -732,51 +736,31 @@ if __name__ == '__main__':
# Set up the signal handler
def sig_handler(_signal, _frame):
logger.info('SHUTDOWN: HBROUTER IS TERMINATING WITH SIGNAL %s', str(_signal))
hblink_handler(_signal, _frame, logger)
hblink_handler(_signal, _frame)
logger.info('SHUTDOWN: ALL SYSTEM HANDLERS EXECUTED - STOPPING REACTOR')
reactor.stop()
# Set signal handers so that we can gracefully exit if need be
for sig in [signal.SIGTERM, signal.SIGINT]:
signal.signal(sig, sig_handler)
# ID ALIAS CREATION
# Download
if CONFIG['ALIASES']['TRY_DOWNLOAD'] == True:
# Try updating peer aliases file
result = try_download(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['PEER_FILE'], CONFIG['ALIASES']['PEER_URL'], CONFIG['ALIASES']['STALE_TIME'])
logger.info(result)
# Try updating subscriber aliases file
result = try_download(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['SUBSCRIBER_FILE'], CONFIG['ALIASES']['SUBSCRIBER_URL'], CONFIG['ALIASES']['STALE_TIME'])
logger.info(result)
# Make Dictionaries
peer_ids = mk_id_dict(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['PEER_FILE'])
if peer_ids:
logger.info('ID ALIAS MAPPER: peer_ids dictionary is available')
subscriber_ids = mk_id_dict(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['SUBSCRIBER_FILE'])
if subscriber_ids:
logger.info('ID ALIAS MAPPER: subscriber_ids dictionary is available')
talkgroup_ids = mk_id_dict(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['TGID_FILE'])
if talkgroup_ids:
logger.info('ID ALIAS MAPPER: talkgroup_ids dictionary is available')
# Create the name-number mapping dictionaries
peer_ids, subscriber_ids, talkgroup_ids = mk_aliases(CONFIG)
# Build the routing rules file
BRIDGES = make_bridges('hb_confbridge_rules')
# INITIALIZE THE REPORTING LOOP
report_server = config_reports(CONFIG, logger, confbridgeReportFactory)
report_server = config_reports(CONFIG, confbridgeReportFactory)
# HBlink instance creation
logger.info('HBlink \'hb_router.py\' (c) 2016 N0MJS & the K0USY Group - SYSTEM STARTING...')
logger.info('HBlink \'hb_confbridge.py\' (c) 2016-2018 N0MJS & the K0USY Group - SYSTEM STARTING...')
for system in CONFIG['SYSTEMS']:
if CONFIG['SYSTEMS'][system]['ENABLED']:
if CONFIG['SYSTEMS'][system]['MODE'] == 'OPENBRIDGE':
systems[system] = routerOBP(system, CONFIG, logger, report_server)
systems[system] = routerOBP(system, CONFIG, report_server)
else:
systems[system] = routerHBP(system, CONFIG, logger, report_server)
systems[system] = routerHBP(system, CONFIG, report_server)
reactor.listenUDP(CONFIG['SYSTEMS'][system]['PORT'], systems[system], interface=CONFIG['SYSTEMS'][system]['IP'])
logger.debug('%s instance created: %s, %s', CONFIG['SYSTEMS'][system]['MODE'], system, systems[system])
@ -793,5 +777,6 @@ if __name__ == '__main__':
stream_trimmer_task = task.LoopingCall(stream_trimmer_loop)
stream_trimmer = stream_trimmer_task.start(5)
stream_trimmer.addErrback(loopingErrHandle)
reactor.run()

17
hb_log.py
View File

@ -1,7 +1,7 @@
#!/usr/bin/env python
#
###############################################################################
# Copyright (C) 2016 Cortney T. Buffington, N0MJS <n0mjs@me.com>
# Copyright (C) 2016-2018 Cortney T. Buffington, N0MJS <n0mjs@me.com>
#
# This program is free software; you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
@ -29,7 +29,7 @@ from logging.config import dictConfig
# Does anybody read this stuff? There's a PEP somewhere that says I should do this.
__author__ = 'Cortney T. Buffington, N0MJS'
__copyright__ = 'Copyright (c) 2016 Cortney T. Buffington, N0MJS and the K0USY Group'
__copyright__ = 'Copyright (c) 2016-2018 Cortney T. Buffington, N0MJS and the K0USY Group'
__credits__ = 'Colin Durbridge, G4EML, Steve Zingman, N4IRS; Mike Zingman, N4IRR; Jonathan Naylor, G4KLX; Hans Barthen, DL5DI; Torsten Shultze, DG1HT'
__license__ = 'GNU GPLv3'
__maintainer__ = 'Cort Buffington, N0MJS'
@ -83,13 +83,12 @@ def config_logging(_logger):
'formatter': 'syslog',
}
},
'loggers': {
_logger['LOG_NAME']: {
'handlers': _logger['LOG_HANDLERS'].split(','),
'level': _logger['LOG_LEVEL'],
'propagate': True,
}
}
'root': {
'handlers': _logger['LOG_HANDLERS'].split(','),
'level': _logger['LOG_LEVEL'],
'propagate': True,
},
})
return logging.getLogger(_logger['LOG_NAME'])

46
hb_parrot.py
View File

@ -1,7 +1,7 @@
#!/usr/bin/env python
#
###############################################################################
# Copyright (C) 2016 Cortney T. Buffington, N0MJS <n0mjs@me.com> (and Mike Zingman N4IRR)
# Copyright (C) 2016-2018 Cortney T. Buffington, N0MJS <n0mjs@me.com> (and Mike Zingman N4IRR)
#
# This program is free software; you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
@ -35,13 +35,18 @@ from twisted.protocols.basic import NetstringReceiver
from twisted.internet import reactor, task
# Things we import from the main hblink module
from hblink import HBSYSTEM, systems, hblink_handler, reportFactory, REPORT_OPCODES, config_reports, build_reg_acl
from hblink import HBSYSTEM, systems, hblink_handler, reportFactory, REPORT_OPCODES, config_reports, mk_aliases
from dmr_utils.utils import hex_str_3, int_id, get_alias
from dmr_utils import decode, bptc, const
import hb_config
import hb_log
import hb_const
# The module needs logging logging, but handlers, etc. are controlled by the parent
import logging
logger = logging.getLogger(__name__)
# Does anybody read this stuff? There's a PEP somewhere that says I should do this.
__author__ = 'Cortney T. Buffington, N0MJS and Mike Zingman, N4IRR'
__copyright__ = 'Copyright (c) 2016 Cortney T. Buffington, N0MJS and the K0USY Group'
@ -55,8 +60,8 @@ __status__ = 'pre-alpha'
class parrot(HBSYSTEM):
def __init__(self, _name, _config, _logger, _report):
HBSYSTEM.__init__(self, _name, _config, _logger, _report)
def __init__(self, _name, _config, _report):
HBSYSTEM.__init__(self, _name, _config, _report)
# Status information for the system, TS1 & TS2
# 1 & 2 are "timeslot"
@ -119,14 +124,14 @@ class parrot(HBSYSTEM):
# Is this is a new call stream?
if (_stream_id != self.STATUS[_slot]['RX_STREAM_ID']):
self.STATUS['RX_START'] = pkt_time
self._logger.info('(%s) *CALL START* STREAM ID: %s SUB: %s (%s) REPEATER: %s (%s) TGID %s (%s), TS %s', \
logger.info('(%s) *CALL START* STREAM ID: %s SUB: %s (%s) REPEATER: %s (%s) TGID %s (%s), TS %s', \
self._system, int_id(_stream_id), get_alias(_rf_src, subscriber_ids), int_id(_rf_src), get_alias(_peer_id, peer_ids), int_id(_peer_id), get_alias(_dst_id, talkgroup_ids), int_id(_dst_id), _slot)
# Final actions - Is this a voice terminator?
if (_frame_type == hb_const.HBPF_DATA_SYNC) and (_dtype_vseq == hb_const.HBPF_SLT_VTERM) and (self.STATUS[_slot]['RX_TYPE'] != hb_const.HBPF_SLT_VTERM):
call_duration = pkt_time - self.STATUS['RX_START']
self._logger.info('(%s) *CALL END* STREAM ID: %s SUB: %s (%s) REPEATER: %s (%s) TGID %s (%s), TS %s, Duration: %s', \
logger.info('(%s) *CALL END* STREAM ID: %s SUB: %s (%s) REPEATER: %s (%s) TGID %s (%s), TS %s, Duration: %s', \
self._system, int_id(_stream_id), get_alias(_rf_src, subscriber_ids), int_id(_rf_src), get_alias(_peer_id, peer_ids), int_id(_peer_id), get_alias(_dst_id, talkgroup_ids), int_id(_dst_id), _slot, call_duration)
self.CALL_DATA.append(_data)
sleep(2)
@ -187,16 +192,13 @@ if __name__ == '__main__':
# Set up the signal handler
def sig_handler(_signal, _frame):
logger.info('SHUTDOWN: HBROUTER IS TERMINATING WITH SIGNAL %s', str(_signal))
hblink_handler(_signal, _frame, logger)
hblink_handler(_signal, _frame)
logger.info('SHUTDOWN: ALL SYSTEM HANDLERS EXECUTED - STOPPING REACTOR')
reactor.stop()
# Set signal handers so that we can gracefully exit if need be
for sig in [signal.SIGTERM, signal.SIGINT]:
signal.signal(sig, sig_handler)
# Build the Access Control List
REG_ACL = build_reg_acl('reg_acl', logger)
# ID ALIAS CREATION
# Download
@ -208,27 +210,21 @@ if __name__ == '__main__':
result = try_download(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['SUBSCRIBER_FILE'], CONFIG['ALIASES']['SUBSCRIBER_URL'], CONFIG['ALIASES']['STALE_TIME'])
logger.info(result)
# Make Dictionaries
peer_ids = mk_id_dict(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['PEER_FILE'])
if peer_ids:
logger.info('ID ALIAS MAPPER: peer_ids dictionary is available')
subscriber_ids = mk_id_dict(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['SUBSCRIBER_FILE'])
if subscriber_ids:
logger.info('ID ALIAS MAPPER: subscriber_ids dictionary is available')
talkgroup_ids = mk_id_dict(CONFIG['ALIASES']['PATH'], CONFIG['ALIASES']['TGID_FILE'])
if talkgroup_ids:
logger.info('ID ALIAS MAPPER: talkgroup_ids dictionary is available')
# Create the name-number mapping dictionaries
peer_ids, subscriber_ids, talkgroup_ids = mk_aliases(CONFIG)
# INITIALIZE THE REPORTING LOOP
report_server = config_reports(CONFIG, logger, reportFactory)
report_server = config_reports(CONFIG, reportFactory)
# HBlink instance creation
logger.info('HBlink \'hb_parrot.py\' (c) 2016 N0MJS & the K0USY Group - SYSTEM STARTING...')
logger.info('HBlink \'hb_parrot.py\' (c) 2016-2018 N0MJS & the K0USY Group - SYSTEM STARTING...')
for system in CONFIG['SYSTEMS']:
if CONFIG['SYSTEMS'][system]['ENABLED']:
systems[system] = parrot(system, CONFIG, logger, report_server)
if CONFIG['SYSTEMS'][system]['MODE'] == 'OPENBRIDGE':
logger.critical('%s FATAL: Instance is mode \'OPENBRIDGE\', \n\t\t...Which would be tragic for parrot, since it carries multiple call\n\t\tstreams simultaneously. hb_parrot.py onlyl works with MMDVM-based systems', system)
sys.exit('hb_parrot.py cannot function with systems that are not MMDVM devices. System {} is configured as an OPENBRIDGE'.format(system))
else:
systems[system] = HBSYSTEM(system, CONFIG, report_server)
reactor.listenUDP(CONFIG['SYSTEMS'][system]['PORT'], systems[system], interface=CONFIG['SYSTEMS'][system]['IP'])
logger.debug('%s instance created: %s, %s', CONFIG['SYSTEMS'][system]['MODE'], system, systems[system])

197
hblink.py
View File

@ -49,12 +49,16 @@ from twisted.internet import reactor, task
import hb_log
import hb_config
import hb_const as const
from dmr_utils.utils import int_id, hex_str_4
from dmr_utils.utils import int_id, hex_str_4, try_download, mk_id_dict
# Imports for the reporting server
import cPickle as pickle
from reporting_const import *
# The module needs logging logging, but handlers, etc. are controlled by the parent
import logging
logger = logging.getLogger(__name__)
# Does anybody read this stuff? There's a PEP somewhere that says I should do this.
__author__ = 'Cortney T. Buffington, N0MJS'
__copyright__ = 'Copyright (c) 2016-2018 Cortney T. Buffington, N0MJS and the K0USY Group'
@ -70,28 +74,28 @@ systems = {}
# Timed loop used for reporting HBP status
#
# REPORT BASED ON THE TYPE SELECTED IN THE MAIN CONFIG FILE
def config_reports(_config, _logger, _factory):
def config_reports(_config, _factory):
if True: #_config['REPORTS']['REPORT']:
def reporting_loop(_logger, _server):
_logger.debug('Periodic reporting loop started')
_server.send_config()
_logger.info('HBlink TCP reporting server configured')
logger.info('HBlink TCP reporting server configured')
report_server = _factory(_config, _logger)
report_server = _factory(_config)
report_server.clients = []
reactor.listenTCP(_config['REPORTS']['REPORT_PORT'], report_server)
reporting = task.LoopingCall(reporting_loop, _logger, report_server)
reporting = task.LoopingCall(reporting_loop, logger, report_server)
reporting.start(_config['REPORTS']['REPORT_INTERVAL'])
return report_server
# Shut ourselves down gracefully by disconnecting from the masters and peers.
def hblink_handler(_signal, _frame, _logger):
def hblink_handler(_signal, _frame):
for system in systems:
_logger.info('SHUTDOWN: DE-REGISTER SYSTEM: %s', system)
logger.info('SHUTDOWN: DE-REGISTER SYSTEM: %s', system)
systems[system].dereg()
# Check a supplied ID against the ACL provided. Returns action (True|False) based
@ -110,17 +114,16 @@ def acl_check(_id, _acl):
#************************************************
class OPENBRIDGE(DatagramProtocol):
def __init__(self, _name, _config, _logger, _report):
def __init__(self, _name, _config, _report):
# Define a few shortcuts to make the rest of the class more readable
self._CONFIG = _config
self._system = _name
self._logger = _logger
self._report = _report
self._config = self._CONFIG['SYSTEMS'][self._system]
self._laststrid = ''
def dereg(self):
self._logger.info('(%s) is mode OPENBRIDGE. No De-Registration required, continuing shutdown', self._system)
logger.info('(%s) is mode OPENBRIDGE. No De-Registration required, continuing shutdown', self._system)
def send_system(self, _packet):
if _packet[:4] == 'DMRD':
@ -128,9 +131,9 @@ class OPENBRIDGE(DatagramProtocol):
_packet += hmac_new(self._config['PASSPHRASE'],_packet,sha1).digest()
self.transport.write(_packet, (self._config['TARGET_IP'], self._config['TARGET_PORT']))
# KEEP THE FOLLOWING COMMENTED OUT UNLESS YOU'RE DEBUGGING DEEPLY!!!!
# self._logger.debug('(%s) TX Packet to OpenBridge %s:%s -- %s', self._system, self._config['TARGET_IP'], self._config['TARGET_PORT'], ahex(_packet))
# logger.debug('(%s) TX Packet to OpenBridge %s:%s -- %s', self._system, self._config['TARGET_IP'], self._config['TARGET_PORT'], ahex(_packet))
else:
self._logger.error('(%s) OpenBridge system was asked to send non DMRD packet', self._system)
logger.error('(%s) OpenBridge system was asked to send non DMRD packet', self._system)
def dmrd_received(self, _peer_id, _rf_src, _dst_id, _seq, _slot, _call_type, _frame_type, _dtype_vseq, _stream_id, _data):
pass
@ -138,7 +141,7 @@ class OPENBRIDGE(DatagramProtocol):
def datagramReceived(self, _packet, _sockaddr):
# Keep This Line Commented Unless HEAVILY Debugging!
#self._logger.debug('(%s) RX packet from %s -- %s', self._system, _sockaddr, ahex(_packet))
#logger.debug('(%s) RX packet from %s -- %s', self._system, _sockaddr, ahex(_packet))
if _packet[:4] == 'DMRD': # DMRData -- encapsulated DMR data frame
_data = _packet[:53]
@ -156,41 +159,41 @@ class OPENBRIDGE(DatagramProtocol):
_frame_type = (_bits & 0x30) >> 4
_dtype_vseq = (_bits & 0xF) # data, 1=voice header, 2=voice terminator; voice, 0=burst A ... 5=burst F
_stream_id = _data[16:20]
#self._logger.debug('(%s) DMRD - Seqence: %s, RF Source: %s, Destination ID: %s', self._system, int_id(_seq), int_id(_rf_src), int_id(_dst_id))
#logger.debug('(%s) DMRD - Seqence: %s, RF Source: %s, Destination ID: %s', self._system, int_id(_seq), int_id(_rf_src), int_id(_dst_id))
# Sanity check for OpenBridge -- all calls must be on Slot 1
if _slot != 1:
self._logger.error('(%s) OpenBridge packet discarded because it was not received on slot 1. SID: %s, TGID %s', self._system, int_id(_rf_src), int_id(_dst_id))
logger.error('(%s) OpenBridge packet discarded because it was not received on slot 1. SID: %s, TGID %s', self._system, int_id(_rf_src), int_id(_dst_id))
return
# ACL Processing
if self._CONFIG['GLOBAL']['USE_ACL']:
if not acl_check(_rf_src, self._CONFIG['GLOBAL']['SUB_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY GLOBAL ACL', self._system, int_id(_stream_id), int_id(_rf_src))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY GLOBAL ACL', self._system, int_id(_stream_id), int_id(_rf_src))
self._laststrid = _stream_id
return
if _slot == 1 and not acl_check(_dst_id, self._CONFIG['GLOBAL']['TG1_ACL']):
if self._laststrid != _stream_id:
self._logger.info('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.info('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
if self._config['USE_ACL']:
if not acl_check(_rf_src, self._config['SUB_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY SYSTEM ACL', self._system, int_id(_stream_id), int_id(_rf_src))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY SYSTEM ACL', self._system, int_id(_stream_id), int_id(_rf_src))
self._laststrid = _stream_id
return
if not acl_check(_dst_id, self._config['TG1_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
# Userland actions -- typically this is the function you subclass for an application
self.dmrd_received(_peer_id, _rf_src, _dst_id, _seq, _slot, _call_type, _frame_type, _dtype_vseq, _stream_id, _data)
else:
self._logger.info('(%s) OpenBridge HMAC failed, packet discarded - OPCODE: %s DATA: %s HMAC LENGTH: %s HMAC: %s', self._system, _packet[:4], repr(_packet[:53]), len(_packet[53:]), repr(_packet[53:]))
logger.info('(%s) OpenBridge HMAC failed, packet discarded - OPCODE: %s DATA: %s HMAC LENGTH: %s HMAC: %s', self._system, _packet[:4], repr(_packet[:53]), len(_packet[53:]), repr(_packet[53:]))
#************************************************
@ -198,11 +201,10 @@ class OPENBRIDGE(DatagramProtocol):
#************************************************
class HBSYSTEM(DatagramProtocol):
def __init__(self, _name, _config, _logger, _report):
def __init__(self, _name, _config, _report):
# Define a few shortcuts to make the rest of the class more readable
self._CONFIG = _config
self._system = _name
self._logger = _logger
self._report = _report
self._config = self._CONFIG['SYSTEMS'][self._system]
self._laststrid = ''
@ -229,18 +231,18 @@ class HBSYSTEM(DatagramProtocol):
# Aliased in __init__ to maintenance_loop if system is a master
def master_maintenance_loop(self):
self._logger.debug('(%s) Master maintenance loop started', self._system)
logger.debug('(%s) Master maintenance loop started', self._system)
for peer in self._peers:
_this_peer = self._peers[peer]
# Check to see if any of the peers have been quiet (no ping) longer than allowed
if _this_peer['LAST_PING']+self._CONFIG['GLOBAL']['PING_TIME']*self._CONFIG['GLOBAL']['MAX_MISSED'] < time():
self._logger.info('(%s) Peer %s (%s) has timed out', self._system, _this_peer['CALLSIGN'], _this_peer['RADIO_ID'])
logger.info('(%s) Peer %s (%s) has timed out', self._system, _this_peer['CALLSIGN'], _this_peer['RADIO_ID'])
# Remove any timed out peers from the configuration
del self._CONFIG['SYSTEMS'][self._system]['PEERS'][peer]
# Aliased in __init__ to maintenance_loop if system is a peer
def peer_maintenance_loop(self):
self._logger.debug('(%s) Peer maintenance loop started', self._system)
logger.debug('(%s) Peer maintenance loop started', self._system)
if self._stats['PING_OUTSTANDING']:
self._stats['NUM_OUTSTANDING'] += 1
# If we're not connected, zero out the stats and send a login request RPTL
@ -251,32 +253,32 @@ class HBSYSTEM(DatagramProtocol):
self._stats['PING_OUTSTANDING'] = False
self._stats['CONNECTION'] = 'RPTL_SENT'
self.send_master('RPTL'+self._config['RADIO_ID'])
self._logger.info('(%s) Sending login request to master %s:%s', self._system, self._config['MASTER_IP'], self._config['MASTER_PORT'])
logger.info('(%s) Sending login request to master %s:%s', self._system, self._config['MASTER_IP'], self._config['MASTER_PORT'])
# If we are connected, sent a ping to the master and increment the counter
if self._stats['CONNECTION'] == 'YES':
self.send_master('RPTPING'+self._config['RADIO_ID'])
self._logger.debug('(%s) RPTPING Sent to Master. Total Sent: %s, Total Missed: %s, Currently Outstanding: %s', self._system, self._stats['PINGS_SENT'], self._stats['PINGS_SENT'] - self._stats['PINGS_ACKD'], self._stats['NUM_OUTSTANDING'])
logger.debug('(%s) RPTPING Sent to Master. Total Sent: %s, Total Missed: %s, Currently Outstanding: %s', self._system, self._stats['PINGS_SENT'], self._stats['PINGS_SENT'] - self._stats['PINGS_ACKD'], self._stats['NUM_OUTSTANDING'])
self._stats['PINGS_SENT'] += 1
self._stats['PING_OUTSTANDING'] = True
def send_peers(self, _packet):
for _peer in self._peers:
self.send_peer(_peer, _packet)
#self._logger.debug('(%s) Packet sent to peer %s', self._system, self._peers[_peer]['RADIO_ID'])
#logger.debug('(%s) Packet sent to peer %s', self._system, self._peers[_peer]['RADIO_ID'])
def send_peer(self, _peer, _packet):
if _packet[:4] == 'DMRD':
_packet = _packet[:11] + _peer + _packet[15:]
self.transport.write(_packet, self._peers[_peer]['SOCKADDR'])
# KEEP THE FOLLOWING COMMENTED OUT UNLESS YOU'RE DEBUGGING DEEPLY!!!!
#self._logger.debug('(%s) TX Packet to %s on port %s: %s', self._peers[_peer]['RADIO_ID'], self._peers[_peer]['IP'], self._peers[_peer]['PORT'], ahex(_packet))
#logger.debug('(%s) TX Packet to %s on port %s: %s', self._peers[_peer]['RADIO_ID'], self._peers[_peer]['IP'], self._peers[_peer]['PORT'], ahex(_packet))
def send_master(self, _packet):
if _packet[:4] == 'DMRD':
_packet = _packet[:11] + self._config['RADIO_ID'] + _packet[15:]
self.transport.write(_packet, self._config['MASTER_SOCKADDR'])
# KEEP THE FOLLOWING COMMENTED OUT UNLESS YOU'RE DEBUGGING DEEPLY!!!!
# self._logger.debug('(%s) TX Packet to %s:%s -- %s', self._system, self._config['MASTER_IP'], self._config['MASTER_PORT'], ahex(_packet))
# logger.debug('(%s) TX Packet to %s:%s -- %s', self._system, self._config['MASTER_IP'], self._config['MASTER_PORT'], ahex(_packet))
def dmrd_received(self, _peer_id, _rf_src, _dst_id, _seq, _slot, _call_type, _frame_type, _dtype_vseq, _stream_id, _data):
pass
@ -284,16 +286,16 @@ class HBSYSTEM(DatagramProtocol):
def master_dereg(self):
for _peer in self._peers:
self.send_peer(_peer, 'MSTCL'+_peer)
self._logger.info('(%s) De-Registration sent to Peer: %s (%s)', self._system, self._peers[_peer]['CALLSIGN'], self._peers[_peer]['RADIO_ID'])
logger.info('(%s) De-Registration sent to Peer: %s (%s)', self._system, self._peers[_peer]['CALLSIGN'], self._peers[_peer]['RADIO_ID'])
def peer_dereg(self):
self.send_master('RPTCL'+self._config['RADIO_ID'])
self._logger.info('(%s) De-Registration sent to Master: %s:%s', self._system, self._config['MASTER_SOCKADDR'][0], self._config['MASTER_SOCKADDR'][1])
logger.info('(%s) De-Registration sent to Master: %s:%s', self._system, self._config['MASTER_SOCKADDR'][0], self._config['MASTER_SOCKADDR'][1])
# Aliased in __init__ to datagramReceived if system is a master
def master_datagramReceived(self, _data, _sockaddr):
# Keep This Line Commented Unless HEAVILY Debugging!
# self._logger.debug('(%s) RX packet from %s -- %s', self._system, _sockaddr, ahex(_data))
# logger.debug('(%s) RX packet from %s -- %s', self._system, _sockaddr, ahex(_data))
# Extract the command, which is various length, all but one 4 significant characters -- RPTCL
_command = _data[:4]
@ -312,39 +314,39 @@ class HBSYSTEM(DatagramProtocol):
_frame_type = (_bits & 0x30) >> 4
_dtype_vseq = (_bits & 0xF) # data, 1=voice header, 2=voice terminator; voice, 0=burst A ... 5=burst F
_stream_id = _data[16:20]
#self._logger.debug('(%s) DMRD - Seqence: %s, RF Source: %s, Destination ID: %s', self._system, int_id(_seq), int_id(_rf_src), int_id(_dst_id))
#logger.debug('(%s) DMRD - Seqence: %s, RF Source: %s, Destination ID: %s', self._system, int_id(_seq), int_id(_rf_src), int_id(_dst_id))
# ACL Processing
if self._CONFIG['GLOBAL']['USE_ACL']:
if not acl_check(_rf_src, self._CONFIG['GLOBAL']['SUB_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY GLOBAL ACL', self._system, int_id(_stream_id), int_id(_rf_src))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY GLOBAL ACL', self._system, int_id(_stream_id), int_id(_rf_src))
self._laststrid = _stream_id
return
if _slot == 1 and not acl_check(_dst_id, self._CONFIG['GLOBAL']['TG1_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
if _slot == 2 and not acl_check(_dst_id, self._CONFIG['GLOBAL']['TG2_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS2 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS2 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
if self._config['USE_ACL']:
if not acl_check(_rf_src, self._config['SUB_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY SYSTEM ACL', self._system, int_id(_stream_id), int_id(_rf_src))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY SYSTEM ACL', self._system, int_id(_stream_id), int_id(_rf_src))
self._laststrid = _stream_id
return
if _slot == 1 and not acl_check(_dst_id, self._config['TG1_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
if _slot == 2 and not acl_check(_dst_id, self._config['TG2_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM TS2 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM TS2 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
@ -355,7 +357,7 @@ class HBSYSTEM(DatagramProtocol):
#self.send_peer(_peer, _data)
self.send_peer(_peer, _data[:11] + _peer + _data[15:])
#self.send_peer(_peer, _data[:11] + self._config['RADIO_ID'] + _data[15:])
#self._logger.debug('(%s) Packet on TS%s from %s (%s) for destination ID %s repeated to peer: %s (%s) [Stream ID: %s]', self._system, _slot, self._peers[_peer_id]['CALLSIGN'], int_id(_peer_id), int_id(_dst_id), self._peers[_peer]['CALLSIGN'], int_id(_peer), int_id(_stream_id))
#logger.debug('(%s) Packet on TS%s from %s (%s) for destination ID %s repeated to peer: %s (%s) [Stream ID: %s]', self._system, _slot, self._peers[_peer_id]['CALLSIGN'], int_id(_peer_id), int_id(_dst_id), self._peers[_peer]['CALLSIGN'], int_id(_peer), int_id(_stream_id))
# Userland actions -- typically this is the function you subclass for an application
@ -390,14 +392,14 @@ class HBSYSTEM(DatagramProtocol):
'SOFTWARE_ID': '',
'PACKAGE_ID': '',
}})
self._logger.info('(%s) Repeater Logging in with Radio ID: %s, %s:%s', self._system, int_id(_peer_id), _sockaddr[0], _sockaddr[1])
logger.info('(%s) Repeater Logging in with Radio ID: %s, %s:%s', self._system, int_id(_peer_id), _sockaddr[0], _sockaddr[1])
_salt_str = hex_str_4(self._peers[_peer_id]['SALT'])
self.send_peer(_peer_id, 'RPTACK'+_salt_str)
self._peers[_peer_id]['CONNECTION'] = 'CHALLENGE_SENT'
self._logger.info('(%s) Sent Challenge Response to %s for login: %s', self._system, int_id(_peer_id), self._peers[_peer_id]['SALT'])
logger.info('(%s) Sent Challenge Response to %s for login: %s', self._system, int_id(_peer_id), self._peers[_peer_id]['SALT'])
else:
self.transport.write('MSTNAK'+_peer_id, _sockaddr)
self._logger.warning('(%s) Invalid Login from Radio ID: %s Denied by Registation ACL', self._system, int_id(_peer_id))
logger.warning('(%s) Invalid Login from Radio ID: %s Denied by Registation ACL', self._system, int_id(_peer_id))
elif _command == 'RPTK': # Repeater has answered our login challenge
_peer_id = _data[4:8]
@ -412,14 +414,14 @@ class HBSYSTEM(DatagramProtocol):
if _sent_hash == _calc_hash:
_this_peer['CONNECTION'] = 'WAITING_CONFIG'
self.send_peer(_peer_id, 'RPTACK'+_peer_id)
self._logger.info('(%s) Peer %s has completed the login exchange successfully', self._system, _this_peer['RADIO_ID'])
logger.info('(%s) Peer %s has completed the login exchange successfully', self._system, _this_peer['RADIO_ID'])
else:
self._logger.info('(%s) Peer %s has FAILED the login exchange successfully', self._system, _this_peer['RADIO_ID'])
logger.info('(%s) Peer %s has FAILED the login exchange successfully', self._system, _this_peer['RADIO_ID'])
self.transport.write('MSTNAK'+_peer_id, _sockaddr)
del self._peers[_peer_id]
else:
self.transport.write('MSTNAK'+_peer_id, _sockaddr)
self._logger.warning('(%s) Login challenge from Radio ID that has not logged in: %s', self._system, int_id(_peer_id))
logger.warning('(%s) Login challenge from Radio ID that has not logged in: %s', self._system, int_id(_peer_id))
elif _command == 'RPTC': # Repeater is sending it's configuraiton OR disconnecting
if _data[:5] == 'RPTCL': # Disconnect command
@ -427,7 +429,7 @@ class HBSYSTEM(DatagramProtocol):
if _peer_id in self._peers \
and self._peers[_peer_id]['CONNECTION'] == 'YES' \
and self._peers[_peer_id]['SOCKADDR'] == _sockaddr:
self._logger.info('(%s) Peer is closing down: %s (%s)', self._system, self._peers[_peer_id]['CALLSIGN'], int_id(_peer_id))
logger.info('(%s) Peer is closing down: %s (%s)', self._system, self._peers[_peer_id]['CALLSIGN'], int_id(_peer_id))
self.transport.write('MSTNAK'+_peer_id, _sockaddr)
del self._peers[_peer_id]
@ -455,10 +457,10 @@ class HBSYSTEM(DatagramProtocol):
_this_peer['PACKAGE_ID'] = _data[262:302]
self.send_peer(_peer_id, 'RPTACK'+_peer_id)
self._logger.info('(%s) Peer %s (%s) has sent repeater configuration', self._system, _this_peer['CALLSIGN'], _this_peer['RADIO_ID'])
logger.info('(%s) Peer %s (%s) has sent repeater configuration', self._system, _this_peer['CALLSIGN'], _this_peer['RADIO_ID'])
else:
self.transport.write('MSTNAK'+_peer_id, _sockaddr)
self._logger.warning('(%s) Peer info from Radio ID that has not logged in: %s', self._system, int_id(_peer_id))
logger.warning('(%s) Peer info from Radio ID that has not logged in: %s', self._system, int_id(_peer_id))
elif _command == 'RPTP': # RPTPing -- peer is pinging us
_peer_id = _data[7:11]
@ -468,18 +470,18 @@ class HBSYSTEM(DatagramProtocol):
self._peers[_peer_id]['PINGS_RECEIVED'] += 1
self._peers[_peer_id]['LAST_PING'] = time()
self.send_peer(_peer_id, 'MSTPONG'+_peer_id)
self._logger.debug('(%s) Received and answered RPTPING from peer %s (%s)', self._system, self._peers[_peer_id]['CALLSIGN'], int_id(_peer_id))
logger.debug('(%s) Received and answered RPTPING from peer %s (%s)', self._system, self._peers[_peer_id]['CALLSIGN'], int_id(_peer_id))
else:
self.transport.write('MSTNAK'+_peer_id, _sockaddr)
self._logger.warning('(%s) Peer info from Radio ID that has not logged in: %s', self._system, int_id(_peer_id))
logger.warning('(%s) Peer info from Radio ID that has not logged in: %s', self._system, int_id(_peer_id))
else:
self._logger.error('(%s) Unrecognized command. Raw HBP PDU: %s', self._system, ahex(_data))
logger.error('(%s) Unrecognized command. Raw HBP PDU: %s', self._system, ahex(_data))
# Aliased in __init__ to datagramReceived if system is a peer
def peer_datagramReceived(self, _data, _sockaddr):
# Keep This Line Commented Unless HEAVILY Debugging!
# self._logger.debug('(%s) RX packet from %s -- %s', self._system, _sockaddr, ahex(_data))
# logger.debug('(%s) RX packet from %s -- %s', self._system, _sockaddr, ahex(_data))
# Validate that we receveived this packet from the master - security check!
if self._config['MASTER_SOCKADDR'] == _sockaddr:
@ -497,39 +499,39 @@ class HBSYSTEM(DatagramProtocol):
_frame_type = (_bits & 0x30) >> 4
_dtype_vseq = (_bits & 0xF) # data, 1=voice header, 2=voice terminator; voice, 0=burst A ... 5=burst F
_stream_id = _data[16:20]
self._logger.debug('(%s) DMRD - Sequence: %s, RF Source: %s, Destination ID: %s', self._system, int_id(_seq), int_id(_rf_src), int_id(_dst_id))
logger.debug('(%s) DMRD - Sequence: %s, RF Source: %s, Destination ID: %s', self._system, int_id(_seq), int_id(_rf_src), int_id(_dst_id))
# ACL Processing
if self._CONFIG['GLOBAL']['USE_ACL']:
if not acl_check(_rf_src, self._CONFIG['GLOBAL']['SUB_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY GLOBAL ACL', self._system, int_id(_stream_id), int_id(_rf_src))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY GLOBAL ACL', self._system, int_id(_stream_id), int_id(_rf_src))
self._laststrid = _stream_id
return
if _slot == 1 and not acl_check(_dst_id, self._CONFIG['GLOBAL']['TG1_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
if _slot == 2 and not acl_check(_dst_id, self._CONFIG['GLOBAL']['TG2_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS2 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY GLOBAL TS2 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
if self._config['USE_ACL']:
if not acl_check(_rf_src, self._config['SUB_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY SYSTEM ACL', self._system, int_id(_stream_id), int_id(_rf_src))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s FROM SUBSCRIBER %s BY SYSTEM ACL', self._system, int_id(_stream_id), int_id(_rf_src))
self._laststrid = _stream_id
return
if _slot == 1 and not acl_check(_dst_id, self._config['TG1_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM TS1 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
if _slot == 2 and not acl_check(_dst_id, self._config['TG2_ACL']):
if self._laststrid != _stream_id:
self._logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM TS2 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
logger.debug('(%s) CALL DROPPED WITH STREAM ID %s ON TGID %s BY SYSTEM TS2 ACL', self._system, int_id(_stream_id), int_id(_dst_id))
self._laststrid = _stream_id
return
@ -540,14 +542,14 @@ class HBSYSTEM(DatagramProtocol):
elif _command == 'MSTN': # Actually MSTNAK -- a NACK from the master
_peer_id = _data[6:10]
if self._config['LOOSE'] or _peer_id == self._config['RADIO_ID']: # Validate the Radio_ID unless using loose validation
self._logger.warning('(%s) MSTNAK Received. Resetting connection to the Master.', self._system)
logger.warning('(%s) MSTNAK Received. Resetting connection to the Master.', self._system)
self._stats['CONNECTION'] = 'NO' # Disconnect ourselves and re-register
elif _command == 'RPTA': # Actually RPTACK -- an ACK from the master
# Depending on the state, an RPTACK means different things, in each clause, we check and/or set the state
if self._stats['CONNECTION'] == 'RPTL_SENT': # If we've sent a login request...
_login_int32 = _data[6:10]
self._logger.info('(%s) Repeater Login ACK Received with 32bit ID: %s', self._system, int_id(_login_int32))
logger.info('(%s) Repeater Login ACK Received with 32bit ID: %s', self._system, int_id(_login_int32))
_pass_hash = sha256(_login_int32+self._config['PASSPHRASE']).hexdigest()
_pass_hash = bhex(_pass_hash)
self.send_master('RPTK'+self._config['RADIO_ID']+_pass_hash)
@ -556,7 +558,7 @@ class HBSYSTEM(DatagramProtocol):
elif self._stats['CONNECTION'] == 'AUTHENTICATED': # If we've sent the login challenge...
_peer_id = _data[6:10]
if self._config['LOOSE'] or _peer_id == self._config['RADIO_ID']: # Validate the Radio_ID unless using loose validation
self._logger.info('(%s) Repeater Authentication Accepted', self._system)
logger.info('(%s) Repeater Authentication Accepted', self._system)
_config_packet = self._config['RADIO_ID']+\
self._config['CALLSIGN']+\
self._config['RX_FREQ']+\
@ -575,35 +577,35 @@ class HBSYSTEM(DatagramProtocol):
self.send_master('RPTC'+_config_packet)
self._stats['CONNECTION'] = 'CONFIG-SENT'
self._logger.info('(%s) Repeater Configuration Sent', self._system)
logger.info('(%s) Repeater Configuration Sent', self._system)
else:
self._stats['CONNECTION'] = 'NO'
self._logger.error('(%s) Master ACK Contained wrong ID - Connection Reset', self._system)
logger.error('(%s) Master ACK Contained wrong ID - Connection Reset', self._system)
elif self._stats['CONNECTION'] == 'CONFIG-SENT': # If we've sent out configuration to the master
_peer_id = _data[6:10]
if self._config['LOOSE'] or _peer_id == self._config['RADIO_ID']: # Validate the Radio_ID unless using loose validation
self._logger.info('(%s) Repeater Configuration Accepted', self._system)
logger.info('(%s) Repeater Configuration Accepted', self._system)
if self._config['OPTIONS']:
self.send_master('RPTO'+self._config['RADIO_ID']+self._config['OPTIONS'])
self._stats['CONNECTION'] = 'OPTIONS-SENT'
self._logger.info('(%s) Sent options: (%s)', self._system, self._config['OPTIONS'])
logger.info('(%s) Sent options: (%s)', self._system, self._config['OPTIONS'])
else:
self._stats['CONNECTION'] = 'YES'
self._logger.info('(%s) Connection to Master Completed', self._system)
logger.info('(%s) Connection to Master Completed', self._system)
else:
self._stats['CONNECTION'] = 'NO'
self._logger.error('(%s) Master ACK Contained wrong ID - Connection Reset', self._system)
logger.error('(%s) Master ACK Contained wrong ID - Connection Reset', self._system)
elif self._stats['CONNECTION'] == 'OPTIONS-SENT': # If we've sent out options to the master
_peer_id = _data[6:10]
if self._config['LOOSE'] or _peer_id == self._config['RADIO_ID']: # Validate the Radio_ID unless using loose validation
self._logger.info('(%s) Repeater Options Accepted', self._system)
logger.info('(%s) Repeater Options Accepted', self._system)
self._stats['CONNECTION'] = 'YES'
self._logger.info('(%s) Connection to Master Completed with options', self._system)
logger.info('(%s) Connection to Master Completed with options', self._system)
else:
self._stats['CONNECTION'] = 'NO'
self._logger.error('(%s) Master ACK Contained wrong ID - Connection Reset', self._system)
logger.error('(%s) Master ACK Contained wrong ID - Connection Reset', self._system)
elif _command == 'MSTP': # Actually MSTPONG -- a reply to RPTPING (send by peer)
_peer_id = _data[7:11]
@ -611,16 +613,16 @@ class HBSYSTEM(DatagramProtocol):
self._stats['PING_OUTSTANDING'] = False
self._stats['NUM_OUTSTANDING'] = 0
self._stats['PINGS_ACKD'] += 1
self._logger.debug('(%s) MSTPONG Received. Pongs Since Connected: %s', self._system, self._stats['PINGS_ACKD'])
logger.debug('(%s) MSTPONG Received. Pongs Since Connected: %s', self._system, self._stats['PINGS_ACKD'])
elif _command == 'MSTC': # Actually MSTCL -- notify us the master is closing down
_peer_id = _data[5:9]
if self._config['LOOSE'] or _peer_id == self._config['RADIO_ID']: # Validate the Radio_ID unless using loose validation
self._stats['CONNECTION'] = 'NO'
self._logger.info('(%s) MSTCL Recieved', self._system)
logger.info('(%s) MSTCL Recieved', self._system)
else:
self._logger.error('(%s) Received an invalid command in packet: %s', self._system, ahex(_data))
logger.error('(%s) Received an invalid command in packet: %s', self._system, ahex(_data))
#
# Socket-based reporting section
@ -649,16 +651,15 @@ class report(NetstringReceiver):
self._factory._logger.error('got unknown opcode')
class reportFactory(Factory):
def __init__(self, config, logger):
def __init__(self, config):
self._config = config
self._logger = logger
def buildProtocol(self, addr):
if (addr.host) in self._config['REPORTS']['REPORT_CLIENTS'] or '*' in self._config['REPORTS']['REPORT_CLIENTS']:
self._logger.debug('Permitting report server connection attempt from: %s:%s', addr.host, addr.port)
logger.debug('Permitting report server connection attempt from: %s:%s', addr.host, addr.port)
return report(self)
else:
self._logger.error('Invalid report server connection attempt from: %s:%s', addr.host, addr.port)
logger.error('Invalid report server connection attempt from: %s:%s', addr.host, addr.port)
return None
def send_clients(self, _message):
@ -670,6 +671,32 @@ class reportFactory(Factory):
self.send_clients(REPORT_OPCODES['CONFIG_SND']+serialized)
# ID ALIAS CREATION
# Download
def mk_aliases(_config):
if _config['ALIASES']['TRY_DOWNLOAD'] == True:
# Try updating peer aliases file
result = try_download(_config['ALIASES']['PATH'], _config['ALIASES']['PEER_FILE'], _config['ALIASES']['PEER_URL'], _config['ALIASES']['STALE_TIME'])
logger.info(result)
# Try updating subscriber aliases file
result = try_download(_config['ALIASES']['PATH'], _config['ALIASES']['SUBSCRIBER_FILE'], _config['ALIASES']['SUBSCRIBER_URL'], _config['ALIASES']['STALE_TIME'])
logger.info(result)
# Make Dictionaries
peer_ids = mk_id_dict(_config['ALIASES']['PATH'], _config['ALIASES']['PEER_FILE'])
if peer_ids:
logger.info('ID ALIAS MAPPER: peer_ids dictionary is available')
subscriber_ids = mk_id_dict(_config['ALIASES']['PATH'], _config['ALIASES']['SUBSCRIBER_FILE'])
if subscriber_ids:
logger.info('ID ALIAS MAPPER: subscriber_ids dictionary is available')
talkgroup_ids = mk_id_dict(_config['ALIASES']['PATH'], _config['ALIASES']['TGID_FILE'])
if talkgroup_ids:
logger.info('ID ALIAS MAPPER: talkgroup_ids dictionary is available')
return peer_ids, subscriber_ids, talkgroup_ids
#************************************************
# MAIN PROGRAM LOOP STARTS HERE
#************************************************
@ -707,7 +734,7 @@ if __name__ == '__main__':
# Set up the signal handler
def sig_handler(_signal, _frame):
logger.info('SHUTDOWN: HBLINK IS TERMINATING WITH SIGNAL %s', str(_signal))
hblink_handler(_signal, _frame, logger)
hblink_handler(_signal, _frame)
logger.info('SHUTDOWN: ALL SYSTEM HANDLERS EXECUTED - STOPPING REACTOR')
reactor.stop()
@ -715,17 +742,19 @@ if __name__ == '__main__':
for sig in [signal.SIGTERM, signal.SIGINT]:
signal.signal(sig, sig_handler)
peer_ids, subscriber_ids, talkgroup_ids = mk_aliases(CONFIG)
# INITIALIZE THE REPORTING LOOP
report_server = config_reports(CONFIG, logger, reportFactory)
report_server = config_reports(CONFIG, reportFactory)
# HBlink instance creation
logger.info('HBlink \'HBlink.py\' (c) 2016-2018 N0MJS & the K0USY Group - SYSTEM STARTING...')
for system in CONFIG['SYSTEMS']:
if CONFIG['SYSTEMS'][system]['ENABLED']:
if CONFIG['SYSTEMS'][system]['MODE'] == 'OPENBRIDGE':
systems[system] = OPENBRIDGE(system, CONFIG, logger, report_server)
systems[system] = OPENBRIDGE(system, CONFIG, report_server)
else:
systems[system] = HBSYSTEM(system, CONFIG, logger, report_server)
systems[system] = HBSYSTEM(system, CONFIG, report_server)
reactor.listenUDP(CONFIG['SYSTEMS'][system]['PORT'], systems[system], interface=CONFIG['SYSTEMS'][system]['IP'])
logger.debug('%s instance created: %s, %s', CONFIG['SYSTEMS'][system]['MODE'], system, systems[system])