From 9eddcf762b80eaa213cc1f682cce2f8814c4c912 Mon Sep 17 00:00:00 2001 From: Cort Buffington Date: Sat, 20 Jul 2013 15:41:21 -0500 Subject: [PATCH] Change Logging Status Moved most info items into debug to make it less chatty --- ipsc.py | 116 ++++++++++++++++++++++++++----------------------- ipsc_logger.py | 2 +- 2 files changed, 63 insertions(+), 55 deletions(-) diff --git a/ipsc.py b/ipsc.py index 3ba7b37..982f18f 100644 --- a/ipsc.py +++ b/ipsc.py @@ -74,46 +74,46 @@ def print_mode_decode(_mode): ts2 = _mode & IPSC_TS2_MSK if link_op == 0b01000000: - logger.info('\t\tPeer Operational') + logger.debug('\t\tPeer Operational') elif link_op == 0b00000000: - logger.info('\t\tPeer Not Operational') + logger.debug('\t\tPeer Not Operational') else: - logger.warning('\t\tPeer Mode Invalid') + logger.info('\t\tPeer Mode Invalid') if link_mode == 0b00000000: - logger.info('\t\tNo RF Interface') + logger.debug('\t\tNo RF Interface') elif link_mode == 0b00010000: - logger.info('\t\tRadio in Analog Mode') + logger.debug('\t\tRadio in Analog Mode') elif link_mode == 0b00100000: - logger.info('\t\tRadio in Digital Mode') + logger.debug('\t\tRadio in Digital Mode') else: - logger.warning('\t\tRadio Mode Invalid') + logger.info('\t\tRadio Mode Invalid') if ts1 == 0b00001000: - logger.info('\t\tIPSC Enabled on TS1') + logger.debug('\t\tIPSC Enabled on TS1') if ts2 == 0b00000010: - logger.info('\t\tIPSC Enabled on TS2') + logger.debug('\t\tIPSC Enabled on TS2') # Gratuituous print-out of the peer list.. Pretty much debug stuff. # def print_peer_list(_network_name): - logger.info('\t%s', _network_name) + logger.debug('\t%s', _network_name) for dictionary in NETWORK[_network_name]['PEERS']: - logger.info('\tIP Address: %s:%s', dictionary['IP'], dictionary['PORT']) - logger.info('\tRADIO ID: %s ', int(binascii.b2a_hex(dictionary['RADIO_ID']), 16)) - logger.info("\tIPSC Mode:") + logger.debug('\tIP Address: %s:%s', dictionary['IP'], dictionary['PORT']) + logger.debug('\tRADIO ID: %s ', int(binascii.b2a_hex(dictionary['RADIO_ID']), 16)) + logger.debug('\tIPSC Mode:') print_mode_decode(dictionary['RAW_MODE']) - logger.info('\tConnection Status: %s', dictionary['STATUS']['CONNECTED']) - logger.info('\tKeepAlives Missed: %s', dictionary['STATUS']['KEEP_ALIVES_MISSED']) - logger.info("") + logger.debug('\tConnection Status: %s', dictionary['STATUS']['CONNECTED']) + logger.debug('\tKeepAlives Missed: %s', dictionary['STATUS']['KEEP_ALIVES_MISSED']) + logger.debug('') #************************************************ #******** *********** -#******** IPSC Network "Engine" *********** +#******** IPSC Network 'Engine' *********** #******** *********** #************************************************ @@ -128,9 +128,14 @@ class IPSC(DatagramProtocol): # def __init__(self, *args, **kwargs): if len(args) == 1: + # Housekeeping: create references to the configuration and status data for this IPSC instance. + # self._network_name = args[0] self._config = NETWORK[self._network_name] args = () + + # Packet 'constructors' - builds the necessary control packets for this IPSC instance + # self.TS_FLAGS = (self._config['LOCAL']['MODE'] + self._config['LOCAL']['FLAGS']) self.MASTER_REG_REQ_PKT = (MASTER_REG_REQ + self._config['LOCAL']['RADIO_ID'] + self.TS_FLAGS + IPSC_VER) self.MASTER_ALIVE_PKT = (MASTER_ALIVE_REQ + self._config['LOCAL']['RADIO_ID'] + self.TS_FLAGS + IPSC_VER) @@ -141,14 +146,18 @@ class IPSC(DatagramProtocol): self.PEER_ALIVE_REPLY_PKT = (PEER_ALIVE_REPLY + self._config['LOCAL']['RADIO_ID'] + self.TS_FLAGS) self._peer_list_new = False else: - logger.error("Unexpected arguments found.") + # If we didn't get called correctly, log it! + # + logger.error('Unexpected arguments found.') # This is called by REACTOR when it starts, We use it to set up the timed # loop for each instance of the IPSC engine # def startProtocol(self): - #logger.debug("*** config: %s", self._config) - #logger.info("") + # Timed loop for IPSC connection establishment and maintenance + # Others could be added later for things like updating a Web + # page, etc.... + # self._call = task.LoopingCall(self.timed_loop) self._loop = self._call.start(self._config['LOCAL']['ALIVE_TIMER']) @@ -166,10 +175,10 @@ class IPSC(DatagramProtocol): def peer_list_received(self, _data, (_host, _port)): self._config['MASTER']['STATUS']['PEER-LIST'] = True self._peer_list_new = True - logger.info("<<- The Peer List has been Received from Master:%s:%s ", _host, _port) + logger.info('<<- The Peer List has been Received from Master:%s:%s ', _host, _port) _num_peers = int(str(int(binascii.b2a_hex(_data[5:7]), 16))[1:]) self._config['LOCAL']['NUM_PEERS'] = _num_peers - logger.info(' There are %s peers in this IPSC Network', _num_peers) + logger.debug(' There are %s peers in this IPSC Network', _num_peers) del self._config['PEERS'][:] for i in range(7, (_num_peers*11)+7, 11): hex_address = (_data[i+4:i+8]) @@ -189,7 +198,7 @@ class IPSC(DatagramProtocol): #************************************************ def timed_loop(self): - print('timed loop started') # temporary debugging to make sure this part runs + logger.debug('timed loop started') # temporary debugging to make sure this part runs _master_connected = self._config['MASTER']['STATUS']['CONNECTED'] _master_alives_missed = self._config['MASTER']['STATUS']['KEEP_ALIVES_MISSED'] _peer_list_rx = self._config['MASTER']['STATUS']['PEER-LIST'] @@ -197,12 +206,12 @@ class IPSC(DatagramProtocol): if (_master_connected == False): reg_packet = hashed_packet(self._config['LOCAL']['AUTH_KEY'], self.MASTER_REG_REQ_PKT) self.transport.write(reg_packet, (self._config['MASTER']['IP'], self._config['MASTER']['PORT'])) - logger.info("->> Master Registration Request To:%s:%s From:%s", self._config['MASTER']['IP'], self._config['MASTER']['PORT'], binascii.b2a_hex(self._config['LOCAL']['RADIO_ID'])) + logger.info('->> Master Registration Request To:%s:%s From:%s', self._config['MASTER']['IP'], self._config['MASTER']['PORT'], binascii.b2a_hex(self._config['LOCAL']['RADIO_ID'])) elif (_master_connected == True): master_alive_packet = hashed_packet(self._config['LOCAL']['AUTH_KEY'], self.MASTER_ALIVE_PKT) self.transport.write(master_alive_packet, (self._config['MASTER']['IP'], self._config['MASTER']['PORT'])) - logger.info("->> Master Keep-alive Sent To:%s:%s", self._config['MASTER']['IP'], self._config['MASTER']['PORT']) + logger.debug('->> Master Keep-alive Sent To:%s:%s', self._config['MASTER']['IP'], self._config['MASTER']['PORT']) self._config['MASTER']['STATUS']['KEEP_ALIVES_SENT'] += 1 if (self._config['MASTER']['STATUS']['KEEP_ALIVES_OUTSTANDING']) > 0: @@ -214,19 +223,19 @@ class IPSC(DatagramProtocol): logger.error('Maximum Master Keep-Alives Missed -- De-registering the Master') else: - logger.error("->> Master in UNKOWN STATE:%s:%s", self._config['MASTER']['IP'], self._config['MASTER']['PORT']) + logger.error('->> Master in UNKOWN STATE:%s:%s', self._config['MASTER']['IP'], self._config['MASTER']['PORT']) if ((_master_connected == True) and (_peer_list_rx == False)): peer_list_req_packet = hashed_packet(self._config['LOCAL']['AUTH_KEY'], self.PEER_LIST_REQ_PKT) self.transport.write(peer_list_req_packet, (self._config['MASTER']['IP'], self._config['MASTER']['PORT'])) - logger.info("->> List Reqested from Master:%s:%s", self._config['MASTER']['IP'], self._config['MASTER']['PORT']) + logger.info('->> List Reqested from Master:%s:%s', self._config['MASTER']['IP'], self._config['MASTER']['PORT']) # Logic problems in the next if.... bad ones. Fix them. if (self._peer_list_new == True): self._peer_list_new = False logger.info('*** NEW PEER LIST RECEIEVED - PROCESSING!') for peer in (self._config['PEERS']): - if (peer['RADIO_ID'] == binascii.b2a_hex(self._config['LOCAL']['RADIO_ID'])): + if (peer['RADIO_ID'] == self._config['LOCAL']['RADIO_ID']): # We are in the peer-list, but don't need to talk to ourselves continue if peer['STATUS']['CONNECTED'] == 0: peer_reg_packet = hashed_packet(self._config['LOCAL']['AUTH_KEY'], self.PEER_REG_REQ_PKT) @@ -234,10 +243,10 @@ class IPSC(DatagramProtocol): logger.info('->> Peer Registration Request To:%s:%s From:%s', peer['IP'], peer['PORT'], binascii.b2a_hex(self._config['LOCAL']['RADIO_ID'])) elif peer['STATUS']['CONNECTED'] == 1: peer_alive_req_packet = hashed_packet(self._config['LOCAL']['AUTH_KEY'], self.PEER_ALIVE_REQ_PKT) - self.transport.write(peer_reg_packet, (peer['IP'], peer['PORT'])) + self.transport.write(peer_alive_req_packet, (peer['IP'], peer['PORT'])) logger.info('->> Peer Keep-Alive Request To:%s:%s From:%s', peer['IP'], peer['PORT'], binascii.b2a_hex(self._config['LOCAL']['RADIO_ID'])) - print('timed loop finished') # temporary debugging to make sure this part runs + logger.debug('timed loop finished') # temporary debugging to make sure this part runs @@ -249,78 +258,77 @@ class IPSC(DatagramProtocol): # call a function or process immediately if only a few actions # def datagramReceived(self, data, (host, port)): - print('datagram received') # temporary debugging to make sure this part runs + logger.debug('datagram received') # temporary debugging to make sure this part runs dest_ip = self._config['MASTER']['IP'] dest_port = self._config['MASTER']['PORT'] - #logger.info("received %r from %s:%d", binascii.b2a_hex(data), host, port) + #logger.debug('received %r from %s:%d', binascii.b2a_hex(data), host, port) _packettype = data[0:1] _peerid = data[1:5] if (_packettype == PEER_ALIVE_REQ): - logger.info("<<- Peer Keep-alive Request From Peer ID %s at:%s:%s", int(binascii.b2a_hex(_peerid), 16), host, port) + logger.debug('<<- Peer Keep-alive Request From Peer ID %s at:%s:%s', int(binascii.b2a_hex(_peerid), 16), host, port) peer_alive_reply_packet = hashed_packet(self._config['LOCAL']['AUTH_KEY'], self.PEER_ALIVE_REPLY_PKT) self.transport.write(peer_alive_reply_packet, (host, port)) - logger.info("->> Peer Keep-alive Reply sent To:%s:%s", host, port) + logger.info('->> Peer Keep-alive Reply sent To:%s:%s', host, port) elif (_packettype == MASTER_ALIVE_REPLY): - logger.info("<<- Master Keep-alive Reply From:%s:%s", host, port) + logger.info('<<- Master Keep-alive Reply From:%s:%s', host, port) elif (_packettype == PEER_ALIVE_REPLY): - self.config['MASTER']['STATUS']['KEEP_ALIVES_OUTSTANDING'] = 0 - logger.info("<<- Peer Keep-alive Reply From:%s:%s", host, port) - + logger.debug('<<- Peer Keep-alive Reply From:%s:%s', host, port) + elif (_packettype == MASTER_REG_REQ): - logger.info("<<- Registration Packet Recieved") + logger.debug('<<- Registration Packet Recieved') elif (_packettype == MASTER_REG_REPLY): self._config['MASTER']['STATUS']['CONNECTED'] = True self._config['MASTER']['STATUS']['KEEP_ALIVES_OUTSTANDING'] = 0 - logger.info("<<- Master Registration Reply From:%s:%s ", host, port) + logger.info('<<- Master Registration Reply From:%s:%s ', host, port) elif (_packettype == PEER_REG_REQ): - logger.info("<<- Peer Registration Request From Peer ID %s at:%s:%s", int(binascii.b2a_hex(_peerid), 16), host, port) + logger.debug('<<- Peer Registration Request From Peer ID %s at:%s:%s', int(binascii.b2a_hex(_peerid), 16), host, port) peer_reg_reply_packet = hashed_packet(self._config['LOCAL']['AUTH_KEY'], self.PEER_REG_REPLY_PKT) self.transport.write(peer_reg_reply_packet, (host, port)) - logger.warning("->> Peer Registration Reply Sent To:%s:%s", host, port) + logger.info('->> Peer Registration Reply Sent To:%s:%s', host, port) elif (_packettype == PEER_REG_REPLY): - logger.warning('<<- Peer Registration Reply From: %s', int(binascii.b2a_hex(_peerid), 16)) + logger.info('<<- Peer Registration Reply From: %s @ IP: %s', int(binascii.b2a_hex(_peerid), 16), host) elif (_packettype == XCMP_XNL): - logger.info("<<- XCMP_XNL From:%s:%s, but we did not indicate XCMP capable!", host, port) + logger.debug('<<- XCMP_XNL From:%s:%s, but we did not indicate XCMP capable!', host, port) elif (_packettype == PEER_LIST_REPLY): self.peer_list_received(data, (host, port)) elif (_packettype == GROUP_VOICE): - logger.info("<<- Group Voice Packet From:%s:%s", host, port) + logger.debug('<<- Group Voice Packet From:%s:%s', host, port) elif (_packettype == PVT_VOICE): - logger.info("<<- Voice Packet From:%s:%s", host, port) + logger.debug('<<- Voice Packet From:%s:%s', host, port) elif (_packettype == GROUP_DATA): - logger.info("<<- Group Data Packet From:%s:%s", host, port) + logger.debug('<<- Group Data Packet From:%s:%s', host, port) elif (_packettype == PVT_DATA): - logger.info("<<- Private Data Packet From From:%s:%s", host, port) + logger.debug('<<- Private Data Packet From From:%s:%s', host, port) elif (_packettype == RPT_WAKE_UP): - logger.warning("<<- Repeater Wake-Up Packet From:%s:%s", host, port) + logger.info('<<- Repeater Wake-Up Packet From:%s:%s', host, port) elif (_packettype == DE_REG_REQ): - logger.warning("<<- Peer De-Registration Request From:%s:%s", host, port) + logger.info('<<- Peer De-Registration Request From:%s:%s', host, port) elif (_packettype == DE_REG_REPLY): - logger.info("<<- Peer De-Registration Reply From:%s:%s", host, port) + logger.debug('<<- Peer De-Registration Reply From:%s:%s', host, port) elif (_packettype in (CALL_CTL_1, CALL_CTL_2, CALL_CTL_3)): - logger.info("<<- Call Control Packet From:%s:%s", host, port) + logger.debug('<<- Call Control Packet From:%s:%s', host, port) else: packet_type = binascii.b2a_hex(_packettype) - logger.error("<<- Received Unprocessed Type %s From:%s:%s", packet_type, host, port) + logger.error('<<- Received Unprocessed Type %s From:%s:%s', packet_type, host, port) @@ -329,7 +337,7 @@ class IPSC(DatagramProtocol): #************************************************ if __name__ == '__main__': - logger.info('SYSTEM STARTING UP') + logger.debug('SYSTEM STARTING UP') for ipsc_network in NETWORK: reactor.listenUDP(NETWORK[ipsc_network]['LOCAL']['PORT'], IPSC(ipsc_network)) reactor.run() \ No newline at end of file diff --git a/ipsc_logger.py b/ipsc_logger.py index 4623c20..c787807 100644 --- a/ipsc_logger.py +++ b/ipsc_logger.py @@ -47,7 +47,7 @@ dictConfig({ 'ipsc': { # 'handlers': ['file-timed', 'console-timed'], 'handlers': ['file-timed', 'console-timed'], - 'level': 'DEBUG', + 'level': 'INFO', 'propagate': True, } }