USE_DB = 0
import ConfigParser
-import sys, os, string, re, pwd, signal
-from traceback import print_tb
+import sys, os, string, re, pwd, signal, math
+import logging, logging.handlers
+from traceback import format_tb
if USE_DB: import pg
from time import time, sleep
from popen2 import popen2
from LATClient import LATClient, LATClientException
from VendingMachine import VendingMachine, VendingException
+from MessageKeeper import MessageKeeper
from HorizScroll import HorizScroll
from random import random, seed
-from Idler import TrainIdler,GrayIdler
+from Idler import TrainIdler,GrayIdler,StringIdler
import socket
from posix import geteuid
+CREDITS="""
+This vending machine software brought to you by:
+Bernard Blackham
+Mark Tearle
+Nick Bannon
+Cameron Patrick
+and a collective of hungry alpacas.
+
+
+
+For a good time call +61 8 6488 3901
+
+
+
+"""
+
GREETING = 'UCC SNACKS'
PIN_LENGTH = 4
SWITCH = 2
KEY = 3
+class DispenseDatabaseException(Exception): pass
+
class DispenseDatabase:
def __init__(self, vending_machine, host, name, user, password):
self.vending_machine = vending_machine
self.db.query('LISTEN vend_requests')
def process_requests(self):
- print 'processing'
+ logging.debug('database processing')
query = 'SELECT request_id, request_slot FROM vend_requests WHERE request_handled = false'
try:
outstanding = self.db.query(query).getresult()
except (pg.error,), db_err:
- sys.stderr.write('Failed to query database: %s\n'%(db_err.strip()))
- return
+ raise DispenseDatabaseException('Failed to query database: %s\n'%(db_err.strip()))
for (id, slot) in outstanding:
(worked, code, string) = self.vending_machine.vend(slot)
- print (worked, code, string)
+ logging.debug (str((worked, code, string)))
if worked:
query = 'SELECT vend_success(%s)'%id
self.db.query(query).getresult()
try:
info = pwd.getpwuid(uid)
except KeyError:
+ logging.info('getting pin for uid %d: user not in password file'%uid)
return None
if info.pw_dir == None: return False
pinfile = os.path.join(info.pw_dir, '.pin')
try:
s = os.stat(pinfile)
except OSError:
+ logging.info('getting pin for uid %d: .pin not found in home directory'%uid)
return None
if s.st_mode & 077:
+ logging.info('getting pin for uid %d: .pin has wrong permissions'%uid)
return None
try:
f = file(pinfile)
except IOError:
+ logging.info('getting pin for uid %d: I cannot read pin file'%uid)
return None
pinstr = f.readline()
f.close()
if not re.search('^'+'[0-9]'*PIN_LENGTH+'$', pinstr):
+ logging.info('getting pin for uid %d: %s not a good pin'%(uid,repr(pinstr)))
return None
return int(pinstr)
def verify_user_pin(uid, pin):
if get_pin(uid) == pin:
info = pwd.getpwuid(uid)
+ logging.info('accepted pin for uid %d (%s)'%(uid,info.pw_name))
return info.pw_name
else:
+ logging.info('refused pin for uid %d'%(uid))
return None
def door_open_mode(v):
- print "Entering open door mode"
+ logging.warning("Entering open door mode")
v.display("-FEED ME-")
while True:
e = v.next_event()
(event, params) = e
if event == DOOR:
if params == 1: # door closed
+ logging.warning('Leaving open door mode')
v.display("-YUM YUM!-")
sleep(1)
return
LEN = 10
return ' '*((LEN-len(str))/2)+str
-class MessageKeeper:
- def __init__(self, vendie):
- # Each element of scrolling_message should be a 3-tuple of
- # ('message', True/False if it is to be repeated, time to display)
- self.scrolling_message = []
- self.v = vendie
- self.next_update = None
-
- def set_message(self, string):
- self.scrolling_message = [(string, False, None)]
- self.update_display(True)
-
- def set_messages(self, strings):
- self.scrolling_message = strings
- self.update_display(True)
-
- def update_display(self, forced = False):
- if not forced and self.next_update != None and time() < self.next_update:
- return
- if len(self.scrolling_message) > 0:
- if len(self.scrolling_message[0][0]) > 10:
- (m, r, t) = self.scrolling_message[0]
- a = []
- exp = HorizScroll(m).expand(padding = 0, wraparound = True)
- if t == None:
- t = 0.1
- else:
- t = t / len(exp)
- for x in exp:
- a.append((x, r, t))
- del self.scrolling_message[0]
- self.scrolling_message = a + self.scrolling_message
- newmsg = self.scrolling_message[0]
- if newmsg[2] != None:
- self.next_update = time() + newmsg[2]
- else:
- self.next_update = None
- self.v.display(self.scrolling_message[0][0])
- if self.scrolling_message[0][1]:
- self.scrolling_message.append(self.scrolling_message[0])
- del self.scrolling_message[0]
- def done(self):
- return len(self.scrolling_message) == 0
+
+idlers = []
+idler = None
+
+def setup_idlers(v):
+ global idlers, idler
+ idlers = [
+ StringIdler(v),
+ StringIdler(v, text=CREDITS),
+ StringIdler(v, text=str(math.pi) + " "),
+ StringIdler(v, text=str(math.e) + " "),
+ GrayIdler(v),
+ TrainIdler(v),
+ GrayIdler(v,one="*",zero="-"),
+ GrayIdler(v,one="/",zero="\\"),
+ GrayIdler(v,one="X",zero="O"),
+ GrayIdler(v,one="*",zero="-",reorder=1),
+ GrayIdler(v,one="/",zero="\\",reorder=1),
+ GrayIdler(v,one="X",zero="O",reorder=1),
+ ]
+ idler = choose_idler()
+
+def choose_idler():
+ global idler
+ idler = idlers[int(random()*len(idlers))]
+ idler.reset()
+
+def idle_step():
+ global idler
+ idler.next()
def run_forever(rfh, wfh, options, cf):
v = VendingMachine(rfh, wfh)
- print 'PING is', v.ping()
+ logging.debug('PING is ' + str(v.ping()))
if USE_DB: db = DispenseDatabase(v, cf.DBServer, cf.DBName, cf.DBUser, cf.DBPassword)
cur_user = ''
mk = MessageKeeper(v)
mk.set_message(GREETING)
time_to_autologout = None
- #idler = TrainIdler(v)
- #idler = GrayIdler(v)
- idler = GrayIdler(v,one="*",zero="-")
+ setup_idlers(v)
time_to_idle = None
last_timeout_refresh = None
while True:
- if USE_DB: db.handle_events()
+ if USE_DB:
+ try:
+ db.handle_events()
+ except DispenseDatabaseException, e:
+ logging.error('Database error: '+str(e))
if time_to_autologout != None:
time_left = time_to_autologout - time()
# start autologout
time_to_autologout = time() + 15
- if time_to_idle == None and cur_user == '': time_to_idle = time() + 60
- if time_to_idle != None and cur_user != '': time_to_idle = None
- if time_to_idle is not None and time() > time_to_idle: idler.next()
+ if time_to_idle == None and cur_user == '':
+ time_to_idle = time() + 5
+ choose_idler()
+ if time_to_idle is not None and cur_user != '': time_to_idle = None
+ if time_to_idle is not None and time() > time_to_idle: idle_step()
+ if time_to_idle is not None and time() > time_to_idle + 300:
+ time_to_idle = time()
+ choose_idler()
mk.update_display()
e = v.next_event(0)
if e == None:
- e = v.next_event(0.1)
+ e = v.next_event(0.05)
if e == None:
continue
time_to_idle = None
(event, params) = e
- print e
+ logging.debug('Got event: ' + repr(e))
if event == DOOR:
if params == 0:
door_open_mode(v);
if len(cur_user) == 5:
uid = int(cur_user)
if not has_good_pin(uid):
+ logging.info('user '+cur_user+' has a bad PIN')
#mk.set_messages(
#[(center('INVALID'), False, 0.7),
#(center('PIN'), False, 0.7),
continue
cur_pin = ''
mk.set_message('PIN: ')
+ logging.info('need pin for user %s'%cur_user)
continue
elif len(cur_pin) < PIN_LENGTH:
if key == 11:
# XXX this should move somewhere else:
if cur_selection == '55':
mk.set_message('OPENSESAME')
+ logging.info('dispensing a door for %s'%username)
if geteuid() == 0:
ret = os.system('su - "%s" -c "dispense door"'%username)
else:
ret = os.system('dispense door')
if ret == 0:
+ logging.info('door opened')
mk.set_message(center('DOOR OPEN'))
else:
+ logging.warning('user %s tried to dispense a bad door'%username)
mk.set_message(center('BAD DOOR'))
sleep(1)
elif cur_selection == '91':
def connect_to_vend(options, cf):
# Open vending machine via LAT?
if options.use_lat:
+ logging.info('Connecting to vending machine using LAT')
latclient = LATClient(service = cf.ServiceName, password = cf.ServicePassword, server_name = cf.ServerName, connect_password = cf.ConnectPassword, priv_password = cf.PrivPassword)
rfh, wfh = latclient.get_fh()
else:
#(rfh, wfh) = popen2('../../virtualvend/vvend.py')
+ logging.info('Connecting to virtual vending machine on %s:%d'%(options.host,options.port))
import socket
sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM, 0)
sock.connect((options.host, options.port))
op = OptionParser(usage="%prog [OPTION]...")
op.add_option('-f', '--config-file', default='/etc/dispense/servers.conf', metavar='FILE', dest='config_file', help='use the specified config file instead of /etc/dispense/servers.conf')
- op.add_option('-v', '--virtualvend', action='store_false', default=True, dest='use_lat', help='use the virtual vending server instead of LAT')
+ op.add_option('--virtualvend', action='store_false', default=True, dest='use_lat', help='use the virtual vending server instead of LAT')
op.add_option('-n', '--hostname', dest='host', default='localhost', help='the hostname to connect to for virtual vending machine mode (default: localhost)')
op.add_option('-p', '--port', dest='port', default=5150, type='int', help='the port number to connect to (default: 5150)')
+ op.add_option('-l', '--log-file', metavar='FILE', dest='log_file', default='', help='log output to the specified file')
+ op.add_option('-s', '--syslog', dest='syslog', metavar='FACILITY', default=None, help='log output to given syslog facility')
+ op.add_option('-d', '--daemon', dest='daemon', action='store_true', default=False, help='run as a daemon')
+ op.add_option('-v', '--verbose', dest='verbose', action='store_true', default=False, help='spit out lots of debug output')
+ op.add_option('-q', '--quiet', dest='quiet', action='store_true', default=False, help='only report errors')
+ op.add_option('--pid-file', dest='pid_file', metavar='FILE', default='', help='store daemon\'s pid in the given file')
options, args = op.parse_args()
if len(args) != 0:
self.__dict__[option] = value
except ConfigParser.Error, e:
- print "Error reading config file "+config_file+": " + str(e)
- sys.exit(1)
+ raise SystemExit("Error reading config file "+config_file+": " + str(e))
+
+def create_pid_file(name):
+ try:
+ pid_file = file(name, 'w')
+ pid_file.write('%d\n'%os.getpid())
+ pid_file.close()
+ except IOError, e:
+ logging.warning('unable to write to pid file '+name+': '+str(e))
+
+def set_stuff_up():
+ def do_nothing(signum, stack):
+ signal.signal(signum, do_nothing)
+ def stop_server(signum, stack): raise KeyboardInterrupt
+ signal.signal(signal.SIGHUP, do_nothing)
+ signal.signal(signal.SIGTERM, stop_server)
+ signal.signal(signal.SIGINT, stop_server)
-def do_vend_server():
options = parse_args()
config_opts = VendConfigFile(options.config_file, config_options)
+ if options.daemon: become_daemon()
+ set_up_logging(options)
+ if options.pid_file != '': create_pid_file(options.pid_file)
+ return options, config_opts
+
+def clean_up_nicely(options, config_opts):
+ if options.pid_file != '':
+ try:
+ os.unlink(options.pid_file)
+ logging.debug('Removed pid file '+options.pid_file)
+ except OSError: pass # if we can't delete it, meh
+
+def set_up_logging(options):
+ logger = logging.getLogger()
+
+ if not options.daemon:
+ stderr_logger = logging.StreamHandler(sys.stderr)
+ stderr_logger.setFormatter(logging.Formatter('%(levelname)s: %(message)s'))
+ logger.addHandler(stderr_logger)
+
+ if options.log_file != '':
+ try:
+ file_logger = logging.FileHandler(options.log_file)
+ file_logger.setFormatter(logging.Formatter('%(asctime)s %(levelname)s: %(message)s'))
+ logger.addHandler(file_logger)
+ except IOError, e:
+ logger.warning('unable to write to log file '+options.log_file+': '+str(e))
+
+ if options.syslog != None:
+ sys_logger = logging.handlers.SysLogHandler('/dev/log', options.syslog)
+ sys_logger.setFormatter(logging.Formatter('vendserver[%d]'%(os.getpid()) + ' %(levelname)s: %(message)s'))
+ logger.addHandler(sys_logger)
+
+ if options.quiet:
+ logger.setLevel(logging.WARNING)
+ elif options.verbose:
+ logger.setLevel(logging.DEBUG)
+ else:
+ logger.setLevel(logging.INFO)
+
+def become_daemon():
+ dev_null = file('/dev/null')
+ fd = dev_null.fileno()
+ os.dup2(fd, 0)
+ os.dup2(fd, 1)
+ os.dup2(fd, 2)
+ try:
+ if os.fork() != 0:
+ sys.exit(0)
+ os.setsid()
+ except OSError, e:
+ raise SystemExit('failed to fork: '+str(e))
+
+def do_vend_server(options, config_opts):
while True:
try:
rfh, wfh = connect_to_vend(options, config_opts)
except (LATClientException, socket.error), e:
(exc_type, exc_value, exc_traceback) = sys.exc_info()
del exc_traceback
- print
- print "Connection error: "+str(exc_type)+" "+str(e)
- print "Trying again in 5 seconds."
+ logging.error("Connection error: "+str(exc_type)+" "+str(e))
+ logging.info("Trying again in 5 seconds.")
sleep(5)
continue
+
try:
run_forever(rfh, wfh, options, config_opts)
except VendingException:
- print
- print "Connection died, trying again..."
+ logging.error("Connection died, trying again...")
+ logging.info("Trying again in 5 seconds.")
+ sleep(5)
if __name__ == '__main__':
- def do_nothing(signum, stack): pass
- def stop_server(signum, stack): raise KeyboardInterrupt
- signal.signal(signal.SIGHUP, do_nothing)
- signal.signal(signal.SIGTERM, stop_server)
- signal.signal(signal.SIGINT, stop_server)
+ options, config_opts = set_stuff_up()
while True:
try:
- do_vend_server()
+ logging.warning('Starting Vend Server')
+ do_vend_server(options, config_opts)
+ logging.error('Vend Server finished unexpectedly, restarting')
except KeyboardInterrupt:
- print "Killed by signal."
+ logging.info("Killed by signal, cleaning up")
+ clean_up_nicely(options, config_opts)
+ logging.warning("Vend Server stopped")
+ break
+ except SystemExit:
break
except:
(exc_type, exc_value, exc_traceback) = sys.exc_info()
- print
- print "Uh-oh, unhandled " + str(exc_type) + " exception"
- print "Message: ", str(exc_value)
- print
- print_tb(exc_traceback)
+ tb = format_tb(exc_traceback, 20)
del exc_traceback
- print
- print "This message should be considered a bug in the Vend Server."
- print "Please report this to someone who can fix it."
- print
- print "Trying again anyway (might not help, but hey...)"
+
+ logging.critical("Uh-oh, unhandled " + str(exc_type) + " exception")
+ logging.critical("Message: " + str(exc_value))
+ logging.critical("Traceback:")
+ for event in tb:
+ for line in event.split('\n'):
+ logging.critical(' '+line)
+ logging.critical("This message should be considered a bug in the Vend Server.")
+ logging.critical("Please report this to someone who can fix it.")
+ sleep(10)
+ logging.warning("Trying again anyway (might not help, but hey...)")