#!/usr/bin/env python import os import dbus import dbus.service import dbus.mainloop.glib from gi.repository import GObject, GLib import sys import time import threading import socket import logging import logging.handlers import syslog import grp import stat import atexit import re import subprocess import struct import fcntl import termios import signal import time import bluetooth # Do we need stty onlcr???? #SerialPortProfile = '00001101-0000-1000-8000-00805f9b34fb' global lg global opts global RFCOMMDIR RFCOMMDIR = '/run/rfcomm' SLAVEDIR='/dev/pts' BLUEZLIB='/var/lib/bluetooth' global TTY_GID # Group-ID number of the TTY group global doterm # If true, this python program is a terminal console. global needpseudot # Login option and pseudoterminal option needpseudot = False global terminatenow terminatenow = False myscript = os.path.basename(__file__) class dopidfile(object): pidPath = "/" def writePidFile(self): global pidPath pid = str(os.getpid()) pidPath = '/run/rfcomm' + '.pid' f = open(pidPath, 'w') f.write(pid) f.close() def rmPidFile(self): try: os.remove(pidPath) except OSError: pass # Log formating class class flog: # priority strings to be used # with the __init__ function priorities = { 'debug': logging.DEBUG, 'info': logging.INFO, 'warn': logging.WARNING, 'warning': logging.WARNING, 'error': logging.ERROR, 'critical': logging.CRITICAL, } def __init__(self,myscript,facility,priority): """ Initialize for logging :param myscript: The name of the python program script :param facility: The syslog facility, such as daemon or user :param priority: The minimum priority to be printed to the log :returns: Nothing :raises TBD: logging class errors. """ name_len = str(len(myscript)) self.myscript = myscript self.log = logging.getLogger(myscript) self.handler = logging.handlers.SysLogHandler(address=('/dev/log'),facility=facility) self.default_fmt = ' %(levelname)-9s %(name)-' + name_len + 's %(message)s' self.verbose_fmt1 = ' %(levelname)-9s %(name)-' + name_len + 's %(threadName)-14s ' self.verbose_fmt2 = ' %(message)s' formatter = logging.Formatter(self.default_fmt) self.handler.setFormatter(formatter) self.log.setLevel(self.priorities[priority]) # Minimum infolevel to log self.log.addHandler(self.handler) self.handler.createLock() def __default(self,func,*args): self.handler.acquire() formatter = logging.Formatter(self.default_fmt) self.handler.setFormatter(formatter) func(*args) self.handler.release() def setThreshold(self,threshold): """ Change the syslog priority threshold :param priority: Character string corresponding to the threshold """ self.handler.acquire() self.log.setLevel(self.priorities[threshold]) # Minimum infolevel to log self.handler.release() def critical(self,*args): """ Prints a variable argument list at critical priority :returns: logging result """ self.__default(self.log.critical,*args) def error(self,*args): """ Prints a variable argument list at error priority :returns: logging result """ self.__default(self.log.error,*args) def warning(self,*args): """ Prints a variable argument list at warning priority :returns: logging result """ self.__default(self.log.warning,*args) # Python has no notice level! def info(self,*args): """ Prints a variable argument list at info priority :returns: logging result """ self.__default(self.log.info,*args) def debug(self,*args): """ Prints a variable argument list at debug priority Printing debug includes function name and line number. :returns: logging result """ caller_frame = sys._getframe().f_back callerfunc = caller_frame.f_code.co_name + '@' + str(caller_frame.f_lineno); callerfunc = callerfunc.ljust(16) self.handler.acquire() log = logging.getLogger(self.myscript) formatter = logging.Formatter(self.verbose_fmt1+callerfunc+self.verbose_fmt2) self.handler.setFormatter(formatter) log.debug(*args) self.handler.release() # End of log handler # Thread to create login process, with # stdin, stdout, stderr matching the file descriptor # This is because NewConnection cannot create threads or # use a mutex. Workarounds are pipes, IPC semamphores, # IPC messaging class logins(object): slavefd = -1 # Thread to wait on our children def IgnoreWait(self,pid): lg.debug("IgnoreWait: Waiting on process pid: %d" % (pid.pid)) pid.wait() lg.debug("login terminated: %d" % (pid.pid)) def StartLogin(self,rpipe,mainloop): datafd='' masters = [] lg.debug("StartLogin enter: rpipe fd=%d" % (rpipe)) while 1: try: datafd=os.read(rpipe,8) except Exception as e: lg.error('os.read error: %s' % (e)) lg.debug('Done with StartLogin, calling quit') for fd in masters: os.close(fd) os.kill(os.getpid(), signal.SIGINT) thread.exit() # Single integer. (slavefd,masterfd) = struct.unpack("ii",bytearray(datafd)) if masterfd > 0: masters.append(masterfd) lg.debug("StartLogin: slavefd %d" % (slavefd)) if slavefd < 0: lg.debug("Told to exit, so exiting StartLogin thread") os.close(rpipe) # We try to close all the masters, as it gets # things wound down in a hurry. for fd in masters: lg.debug('StartLogin: Try to close fd %d' % (fd)) try: os.close(fd) except Exception as e: lg.debug('StartLogin (ignore error): OK: Did not close fd: %d %s' % (fd,e)) sys.exc_clear() os.kill(os.getpid(), signal.SIGINT) thread.exit() # Start login with fd, and close it. Env = {'TERM': 'dumb'} self.slavefd = slavefd lg.debug('Popen slavefd: %d' % (slavefd)) try: # Mar 16 14:23:35 mtcdt daemon.err ERROR rfcomm.py Popen login: global name 's' is not defined pid = subprocess.Popen(['/bin/login','--'],env=Env,preexec_fn = lambda: ( os.setsid(),fcntl.ioctl(0, termios.TIOCSCTTY, 0) ),stdin=slavefd,stdout=slavefd,stderr=slavefd,close_fds=True,cwd='/') lg.debug('Start IgnoreWait thread') try: IgnoreWaitThread = threading.Thread(target=self.IgnoreWait,args=[pid]) except Exception as e: lg.error('IgnoreWaitThread: threading.Thread: %s' % (e)) try: IgnoreWaitThread.start() except Exception as e: lg.error('IgnoreWaitThread: start: %s' % (e)) except Exception as e: lg.error('Popen login: %s' % (e)) os.close(slavefd) class Profile(dbus.service.Object): fd = -1 readThread = None path = None io_id = -1 io_id2 = -1 hup_id = -1 hup_id2 = -1 io_pty_master = -1 io_pty_slave = -1 slavePath = None linkPath = None w = -1 # True False pseudonyms for making code readable (or not!) exiting = True notexiting = False @dbus.service.method('org.bluez.Profile1', in_signature='', out_signature='') def Release(self): lg.info('Release/quit') mainloop.quit() @dbus.service.method("org.bluez.Profile1", in_signature="", out_signature="") def Cancel(self): lg.info("Cancel") def removeLink(self,state): lg.debug('removeLink: state: %r' % (state)) path = self.linkPath lg.debug('removeLink: path %s' % (path)) if state == self.exiting: lg.debug('Clearing out linkPath') self.linkPath = None # Burn bridges, do it once. if path and os.path.lexists(path): try: os.remove(path) except Exception as e: lg.error("os.remove(self.linkPath): Tried to remove %s" % (path)) lg.error('%s' % (e)) # New Connection is called when a new Bluetooth # is established @dbus.service.method('org.bluez.Profile1', in_signature='oha{sv}', out_signature='') def NewConnection(self, path, fd, properties): dbus.mainloop.glib.threads_init() self.fd = fd.take() # Extract File Descriptor from dbus UnixFD class. self.path = path # Bluetooth address portion of the path address = os.path.basename(self.path) numaddr = address[address.find("_")+1:] # Replace _ with : Name = bluetooth.lookup_name(numaddr.replace("_",":")) print('NewConnection(%s, %s, %s:%d)' % (path,Name,type(fd).__name__,self.fd)) lg.info('NewConnection(%s, %s, %s:%d)' % (path,Name,type(fd).__name__,self.fd)) atexit.register(self.RequestDisconnection,self.path) lg.debug('Past atexit.register') # Get a pseudoterminal to provide an I/O driver for # a program that needs a TTY. if needpseudot: (self.io_pty_master,self.io_pty_slave) = os.openpty() slavestat = os.fstat(self.io_pty_slave) self.minor = os.minor(slavestat.st_rdev) lg.debug('pseudoterminal major and minor: (%d,%d)' % (os.major(slavestat.st_rdev),self.minor)) if not os.path.isdir(RFCOMMDIR): lg.debug('Before mkdir: RFCOMMDIR %s' % (RFCOMMDIR)) os.mkdir(RFCOMMDIR,0o755) lg.debug('Address %s' % (address)) self.linkPath = RFCOMMDIR + '/' + address + '_' + Name + '_pts' + str(self.minor) self.slavePath = SLAVEDIR + '/' + str(self.minor) lg.debug('termPath %s' % (self.linkPath)) self.removeLink(self.notexiting) # linkPath was removed lg.debug('os.symlink(%s,%s)' % (self.slavePath,self.linkPath)) old = os.umask(0o002) lg.debug('past umask') try: os.symlink(self.slavePath,self.linkPath) try: atexit.register(self.removeLink,self.exiting); except Exception as e: lg.error('Register atexit: %s' % (e)) except Exception as e: lg.error('symlink failed: %s' % (e)) return False lg.debug('Before umask') os.umask(old) lg.debug('After umask') # os.chown(self.myPath,0,TTY_GID) # Completed pseudoterminal case to create device and node # + For loopback, we only monitor the RFCOMM line (self.fd). # + For interactive (not pseudoterminal or loopback option, # we monitor the stdin (0) and the RFCOMM line for input # + For pseudoterminal, we monitor input on the RFCOMM line, # and the slave pseudoterminal. # Note that io_add_watch causes a poll to be done by the # python GI library. The callback functions (io_term and io_cb) # will be called when there is an event on the file descriptor # being polled. sys.stdout.flush() if not opts.loopback: if needpseudot: local_fd = self.io_pty_master lg.debug('NewConnection: master_fd: %d slave_fd: %d' % (local_fd,self.io_pty_slave)) #success to here. else: # stdin local_fd = 0 lg.debug('Ready to do io_add_watch on local_fd: %d' % (local_fd)) try: self.io_id2 = GObject.io_add_watch(local_fd, GObject.PRIORITY_DEFAULT, GObject.IO_IN | GObject.IO_PRI | GObject.IO_HUP | GObject.IO_ERR, self.io_term) except Exception as e: lg.error('io_addwatch failed for local_fd %d: IO_IN, IO_PRI %s' % (local_fd,e)) if opts.login: # Writing the slave file descriptor causes the login process to start. lg.debug('opts.login is true slave fd: %d pipe: %d' % (self.io_pty_slave,self.w)) try: os.write(self.w,struct.pack('ii',self.io_pty_slave,self.io_pty_master)) except Exception as e: lg.error('os.write of slave fd:%d master fd: %d failed: %s' % (self.io_pty_slave,self.io_pty_slave,e)) os.close(self.io_pty_slave) self.io_pty_slave = -1 return False self.io_pty_slave = -1 if doterm: lg.debug('Profile: Write the prompt') os.write(1,'TTY> ') lg.debug('NewConnection: doterm: %s, io_add_watch is next' % doterm) self.io_id = GObject.io_add_watch(self.fd, GObject.PRIORITY_DEFAULT, GObject.IO_IN | GObject.IO_PRI | GObject.IO_HUP | GObject.IO_ERR, self.io_cb) lg.debug('io_id(remote input) = %d io_id2(local input) = %d' % (self.io_id,self.io_id2)) # I/O read from Bluetooth remote to local application. def io_cb(self, fd, conditions): if terminatenow: self.RequestDisconnection(self.path) if (conditions & GObject.IO_HUP or conditions & GObject.IO_ERR): lg.debug('Found HUP on fd: %d, so terminate' % (fd)) self.RequestDisconnection(self.path) return False # Read from remote data = None try: data = os.read(fd, 1024) except: return True lg.debug('io_cb: past read: doterm: %s' % doterm) if opts.loopback: toutput = fd # same as input else: toutput = self.io_pty_master if opts.loopback or needpseudot or opts.login: if data: start = 0 remain = len(data) result = 1 lg.debug('remain is %d entering the loop' % (remain)) while remain > 0 and result > 0: try: result = os.write(toutput,data) except Exception as e: lg.debug('os.write failed: %s' % (e)) return True lg.debug('os.write returned %d for %s remain: %d' % (result,data,remain)) if remain != result and remain > 0: remain -= result lg.debug('remain is now %d result is %d' % (remain,result)) data = data[-remain:] lg.debug('remain to print %s' % (data)) else: remain = 0 lg.debug('returning true to end this routing') return True if data and len(data) > 0: final = data[-1] if data[-1] == '\n': date = data[:-1] if doterm: print('\n'+data.decode('ascii')) os.write(1,'TTY> ') return True # I/O written to bluetooth from local slave (application write to remote) def io_term(self, fd0, conditions): if terminatenow: self.RequestDisconnection(self.path) if (conditions & GObject.IO_HUP or conditions & GObject.IO_ERR): lg.debug('Found HUP on fd0: %d, so terminate' % (fd0)) self.RequestDisconnection(self.path) return False # Read from local (not used for loopback) data = None data = os.read(fd0, 1024) lg.debug('io_term: fd0: %d len(data): %d' % (fd0,len(data))) if not data: # No Data == EOF self.RequestDisconnection(self.path) return True #for character in data: # print character, character.encode('hex') try: os.write(self.fd,data) except Exception as e: print('%s' % e) lg.error('%s' % (e)) self.RequestDisconnection(self.path) return True if doterm: os.write(fd0,'TTY> ') return True @dbus.service.method('org.bluez.Profile1', in_signature='o', out_signature='') def RequestDisconnection(self, path): print('RequestDisconnection(%s)' % (path)) lg.info('RequestDisconnection(%s)' % (path)) if self.fd != -1: lg.debug('closing fd: %s' % (self.fd)) s = socket.fromfd(self.fd,socket.AF_INET,socket.SOCK_STREAM) result = s.shutdown(socket.SHUT_RDWR) lg.debug('After shutdown fd: %s %s %s' % (self.fd,' result:',result)) result = os.close(self.fd) lg.debug('After closing fd: %s %s %s' % (self.fd,' result:',result)) self.fd = -1 if self.io_id != -1: lg.debug('remove id: %s' % (self.io_id)) rmv = GObject.source_remove(self.io_id) self.io_id = -1 if self.io_id2 != -1: lg.debug('closing id2: %s' % (self.io_id2)) rmv = GObject.source_remove(self.io_id2) lg.debug('removed id2: %s %s %s' % (self.io_id2,'result: ',rmv)) self.io_id2 = -1 if self.hup_id != -1: lg.debug('closing hup_id: %s' % (self.hup_id)) rmv = GObject.source_remove(self.hup_id) lg.debug('removed id2: %s %s %s' % (self.hup_id,'result: ',rmv)) self.hup_id = -1 if self.hup_id2 != -1: lg.debug('closing hup_id2: %s' % (self.hup_id2)) rmv = GObject.source_remove(self.hup_id2) lg.debug('removed id2: %s %s %s' % (self.hup_id2,'result: ',rmv)) self.hup_id2 = -1 if needpseudot: if self.io_pty_slave != -1: os.close(self.io_pty_slave) self.io_pty_slave = -1 if self.io_pty_master != -1: try: savefd = self.io_pty_master self.io_pty_master = -1 os.close(savefd) except Exception as e: lg.error("close(io_pty_master): Tried to close %d" % (savefd)) lg.error('%s' % (e)) self.removeLink(self.exiting) def terminationHandler(mainloop): lg.debug('SIGTERM: terminationHandler was called') mainloop.quit() if __name__ == '__main__': import argparse doterm = False TTY_GID = grp.getgrnam('tty').gr_gid # Set up logging initially info and above lg = flog(myscript,'daemon','info') parser = argparse.ArgumentParser( description='BlueZ RFCOMM server.') parser.add_argument('-u', '--uuid', metavar='uuid_or_shortcut', default='spp', help='Service UUID to use. Can be either full UUID' ' or one of the shortcuts: gn, panu, nap. Default: %(default)s.') parser.add_argument('--pseudoterminal', action='store_true', help='Create a pseudoterminal and put slave in /run/rfcomm' ' Suitable for background operation.') parser.add_argument('--loopback', action='store_true', help='Echo data for testing (exclusive with pseudoterminal)') parser.add_argument('--debug', action='store_true', help='Verbose operation mode.') parser.add_argument('--login', action='store_true', help='Use RFCOMM to log into this device.') opts = parser.parse_args() if opts.debug: lg.setThreshold('debug') if opts.pseudoterminal and opts.loopback: msg = 'Cannot have both pseudoterminal and loopback option' print(msg) lg.error(msg) exit(1) if not opts.pseudoterminal and not opts.loopback and not opts.login: doterm = True print("main: doterm is %s" % (str(doterm))) if opts.pseudoterminal or opts.login: needpseudot = True dbus.mainloop.glib.DBusGMainLoop(set_as_default=True) bus = dbus.SystemBus() manager = dbus.Interface(bus.get_object('org.bluez', '/org/bluez'), 'org.bluez.ProfileManager1') mainloop = GObject.MainLoop() GLib.unix_signal_add(GLib.PRIORITY_HIGH,signal.SIGTERM,terminationHandler,mainloop) mypidfile = dopidfile() mypidfile.writePidFile() if opts.login: # Need to create thead to exec logins. rpipe,wpipe = os.pipe() loginProcess = logins() Profile.w = wpipe lg.debug('Call StartLogin threading next') try: StartLoginThread = threading.Thread(target=loginProcess.StartLogin,args=[rpipe,mainloop]) except Exception as e: lg.error('threading.Thread: StartLogin %s' % (e)) try: StartLoginThread.start() except Exception as e: lg.error('StartLogin.start: %s' % (e)) profile_path = '/foo/bar/profile' SPP_opts = { 'AutoConnect': True, 'Role': 'server', 'Name': 'SerialPort' } print('Starting Serial Port Profile...') lg.info('Starting Serial Port Profile...') profile = Profile(bus, profile_path) try: manager.RegisterProfile(profile_path, opts.uuid, SPP_opts) except dbus.exceptions.DBusException as inst: print('dbus exception:',inst._dbus_error_name) lg.error('dbus exception: %s',inst._dbus_error_name) if inst._dbus_error_name == 'org.freedesktop.DBus.Error.AccessDenied': print('Try running as root') exit(1) lg.debug('Completed Register Profile...') dbus.mainloop.glib.threads_init() lg.debug('Completed threads init... Now mainloop.run') try: mainloop.run() except KeyboardInterrupt: pass except Exception as e: lg.error('mainloop exception: %s' % (e)) print('\nSerial Port Profile: ERROR Goodbye') lg.error('Serial Port Profile: ERROR Goodbye') data = struct.pack('i',-1) os.write(wpipe,data) mainloop.quit() lg.info('Serial Port Profile: Goodbye') if opts.login: data = struct.pack('ii',-1,-1) os.write(wpipe,data) mypidfile.rmPidFile() mainloop.quit()