do even more logging
[zanchey/dispense2.git] / sql-edition / servers / VendServer.py
index b173d3c..a09ac2a 100755 (executable)
@@ -3,14 +3,20 @@
 
 USE_DB = 0
 
-import sys, os, string, re, pwd
+import ConfigParser
+import sys, os, string, re, pwd, signal
+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
-from VendingMachine import VendingMachine
-from ConfigParser import ConfigParser
+from LATClient import LATClient, LATClientException
+from VendingMachine import VendingMachine, VendingException
 from HorizScroll import HorizScroll
+from random import random, seed
+from Idler import TrainIdler,GrayIdler
+import socket
+from posix import geteuid
 
 GREETING = 'UCC SNACKS'
 PIN_LENGTH = 4
@@ -19,6 +25,8 @@ DOOR = 1
 SWITCH = 2
 KEY = 3
 
+class DispenseDatabaseException(Exception): pass
+
 class DispenseDatabase:
        def __init__(self, vending_machine, host, name, user, password):
                self.vending_machine = vending_machine
@@ -26,16 +34,15 @@ class DispenseDatabase:
                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()
@@ -56,8 +63,13 @@ def scroll_options(username, mk, welcome = False):
        else:
                msg = []
        choices = ' '*10+'CHOICES: '
-       coke_machine = file('/home/other/coke/coke_contents')
-       cokes = coke_machine.readlines()
+       try:
+               coke_machine = file('/home/other/coke/coke_contents')
+               cokes = coke_machine.readlines()
+               coke_machine.close()
+       except:
+               cokes = []
+               pass
        for c in cokes:
                c = c.strip()
                (slot_num, price, slot_name) = c.split(' ', 2)
@@ -65,7 +77,8 @@ def scroll_options(username, mk, welcome = False):
                choices += '%s8-%s (%sc) '%(slot_num, slot_name, price)
        choices += '55-DOOR '
        choices += 'OR A SNACK. '
-       choices += '99 TO READ AGAIN.'
+       choices += '99 TO READ AGAIN. '
+       choices += 'CHOICE?   '
        msg.append((choices, False, None))
        mk.set_messages(msg)
 
@@ -102,19 +115,44 @@ def verify_user_pin(uid, pin):
        else:
                return None
 
-def door_open_mode(vending_machine):
-       print "Entering open door mode"
-       v.display("DOOR  OPEN")
+def door_open_mode(v):
+       logging.warning("Entering open door mode")
+       v.display("-FEED  ME-")
        while True:
                e = v.next_event()
                if e == None: break
                (event, params) = e
                if event == DOOR:
                        if params == 1: # door closed
-                               v.display("BYE BYE!")
+                               logging.warning('Leaving open door mode')
+                               v.display("-YUM YUM!-")
                                sleep(1)
                                return
 
+def cookie(v):
+       seed(time())
+       messages = ['  WASSUP! ', 'PINK FISH ', ' SECRETS ', '  ESKIMO  ', ' FORTUNES ', 'MORE MONEY']
+       choice = int(random()*len(messages))
+       msg = messages[choice]
+       left = range(len(msg))
+       for i in range(len(msg)):
+               if msg[i] == ' ': left.remove(i)
+       reveal = 1
+       while left:
+               s = ''
+               for i in range(0, len(msg)):
+                       if i in left:
+                               if reveal == 0:
+                                       left.remove(i)
+                                       s += msg[i]
+                               else:
+                                       s += chr(int(random()*26)+ord('A'))
+                               reveal += 1
+                               reveal %= 17
+                       else:
+                               s += msg[i]
+               v.display(s)
+
 def center(str):
        LEN = 10
        return ' '*((LEN-len(str))/2)+str
@@ -142,7 +180,7 @@ class MessageKeeper:
                        if len(self.scrolling_message[0][0]) > 10:
                                (m, r, t) = self.scrolling_message[0]
                                a = []
-                               exp = HorizScroll(m).expand(padding = 10)
+                               exp = HorizScroll(m).expand(padding = 0, wraparound = True)
                                if t == None:
                                        t = 0.1
                                else:
@@ -164,60 +202,54 @@ class MessageKeeper:
        def done(self):
                return len(self.scrolling_message) == 0
 
-if __name__ == '__main__':
-       cp = ConfigParser()
-       cp.read('/etc/dispense/servers.conf')
-       DBServer = cp.get('Database', 'Server')
-       DBName = cp.get('Database', 'Name')
-       DBUser = cp.get('VendingMachine', 'DBUser')
-       DBPassword = cp.get('VendingMachine', 'DBPassword')
-
-       ServiceName = cp.get('VendingMachine', 'ServiceName')
-       ServicePassword = cp.get('VendingMachine', 'Password')
-       # Open vending machine via LAT
-       if 0:
-               latclient = LATClient(service = ServiceName, password = ServicePassword)
-               (rfh, wfh) = latclient.get_fh()
-       else:
-               #(rfh, wfh) = popen2('../../virtualvend/vvend.py')
-               import socket
-               sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM, 0)
-               sock.connect(('localhost', 5150))
-               rfh = sock.makefile('r')
-               wfh = sock.makefile('w')
+def run_forever(rfh, wfh, options, cf):
        v = VendingMachine(rfh, wfh)
-       print 'PING is', v.ping()
+       logging.debug('PING is', v.ping())
 
-       if USE_DB: db = DispenseDatabase(v, DBServer, DBName, DBUser, DBPassword)
+       if USE_DB: db = DispenseDatabase(v, cf.DBServer, cf.DBName, cf.DBUser, cf.DBPassword)
        cur_user = ''
        cur_pin = ''
        cur_selection = ''
 
        mk = MessageKeeper(v)
        mk.set_message(GREETING)
-       logout_timeout = None
+       time_to_autologout = None
+       #idler = TrainIdler(v)
+       #idler = GrayIdler(v)
+       idler = GrayIdler(v,one="*",zero="-")
+       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 logout_timeout != None:
-                       time_left = logout_timeout - time()
-                       if time_left < 10 and (last_timeout_refresh is None or last_timeout_refresh > time_left):
+               if time_to_autologout != None:
+                       time_left = time_to_autologout - time()
+                       if time_left < 6 and (last_timeout_refresh is None or last_timeout_refresh > time_left):
                                mk.set_message('LOGOUT: '+str(int(time_left)))
                                last_timeout_refresh = int(time_left)
+                               cur_selection = ''
 
-               if logout_timeout != None and logout_timeout - time() <= 0:
-                       logout_timeout = None
+               if time_to_autologout != None and time_to_autologout - time() <= 0:
+                       time_to_autologout = None
                        cur_user = ''
                        cur_pin = ''
                        cur_selection = ''
                        mk.set_message(GREETING)
 
-               if logout_timeout and not mk.done(): logout_timeout = None
-               if len(cur_pin) == PIN_LENGTH and mk.done() and logout_timeout == None:
+               if time_to_autologout and not mk.done(): time_to_autologout = None
+               if cur_user == '' and time_to_autologout: time_to_autologout = None
+               if len(cur_pin) == PIN_LENGTH and mk.done() and time_to_autologout == None:
                        # start autologout
-                       logout_timeout = time() + 10
+                       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()
 
                mk.update_display()
 
@@ -226,8 +258,9 @@ if __name__ == '__main__':
                        e = v.next_event(0.1)
                        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);
@@ -250,10 +283,13 @@ if __name__ == '__main__':
                                if len(cur_user) == 5:
                                        uid = int(cur_user)
                                        if not has_good_pin(uid):
+                                               #mk.set_messages(
+                                                       #[(center('INVALID'), False, 0.7),
+                                                        #(center('PIN'), False, 0.7),
+                                                        #(center('SETUP'), False, 1.0),
+                                                        #(GREETING, False, None)])
                                                mk.set_messages(
-                                                       [(center('INVALID'), False, 0.7),
-                                                        (center('PIN'), False, 0.7),
-                                                        (center('SETUP'), False, 1.0),
+                                                       [(' '*10+'INVALID PIN SETUP'+' '*10, False, 3),
                                                         (GREETING, False, None)])
                                                cur_user = ''
                                                cur_pin = ''
@@ -293,15 +329,17 @@ if __name__ == '__main__':
                                        cur_pin = ''
                                        cur_user = ''
                                        cur_selection = ''
-                                       v.display('BYE!')
-                                       sleep(0.5)
-                                       mk.set_message(GREETING)
+                                       mk.set_messages(
+                                               [(center('BYE!'), False, 1.5),
+                                                (GREETING, False, None)])
                                        continue
                                cur_selection += chr(key + ord('0'))
                                mk.set_message('SELECT: '+cur_selection)
+                               time_to_autologout = None
                        elif len(cur_selection) == 1:
                                if key == 11:
                                        cur_selection = ''
+                                       time_to_autologout = None
                                        scroll_options(username, mk)
                                        continue
                                else:
@@ -309,8 +347,18 @@ if __name__ == '__main__':
                                        #make_selection(cur_selection)
                                        # XXX this should move somewhere else:
                                        if cur_selection == '55':
-                                               v.display('GOT DOOR?')
-                                               os.system('su - "%s" -c "dispense door"'%username)
+                                               mk.set_message('OPENSESAME')
+                                               if geteuid() == 0:
+                                                       ret = os.system('su - "%s" -c "dispense door"'%username)
+                                               else:
+                                                       ret = os.system('dispense door')
+                                               if ret == 0:
+                                                       mk.set_message(center('DOOR OPEN'))
+                                               else:
+                                                       mk.set_message(center('BAD DOOR'))
+                                               sleep(1)
+                                       elif cur_selection == '91':
+                                               cookie(v)
                                        elif cur_selection == '99':
                                                scroll_options(username, mk)
                                                cur_selection = ''
@@ -325,4 +373,185 @@ if __name__ == '__main__':
                                        v.display('THANK YOU')
                                        sleep(0.5)
                                        cur_selection = ''
-                                       logout_timeout = time() + 10
+                                       time_to_autologout = time() + 8
+
+def connect_to_vend(options, cf):
+       # Open vending machine via LAT?
+       if options.use_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')
+               import socket
+               sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM, 0)
+               sock.connect((options.host, options.port))
+               rfh = sock.makefile('r')
+               wfh = sock.makefile('w')
+               
+       return rfh, wfh
+
+def parse_args():
+       from optparse import OptionParser
+
+       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('--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', action='store_true', default=False, help='log output to syslog')
+       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:
+               op.error('extra command line arguments: ' + ' '.join(args))
+
+       return options
+
+config_options = {
+       'DBServer': ('Database', 'Server'),
+       'DBName': ('Database', 'Name'),
+       'DBUser': ('VendingMachine', 'DBUser'),
+       'DBPassword': ('VendingMachine', 'DBPassword'),
+       
+       'ServiceName': ('VendingMachine', 'ServiceName'),
+       'ServicePassword': ('VendingMachine', 'Password'),
+       
+       'ServerName': ('DecServer', 'Name'),
+       'ConnectPassword': ('DecServer', 'ConnectPassword'),
+       'PrivPassword': ('DecServer', 'PrivPassword'),
+       }
+
+class VendConfigFile:
+       def __init__(self, config_file, options):
+               try:
+                       cp = ConfigParser.ConfigParser()
+                       cp.read(config_file)
+
+                       for option in options:
+                               section, name = options[option]
+                               value = cp.get(section, name)
+                               self.__dict__[option] = value
+               
+               except ConfigParser.Error, e:
+                       logging.critical("Error reading config file "+config_file+": " + str(e))
+                       logging.critical("Bailing out")
+                       sys.exit(1)
+
+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)
+
+       options = parse_args()
+       set_up_logging(options)
+       config_opts = VendConfigFile(options.config_file, config_options)
+       if options.daemon: become_daemon()
+       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()
+       
+       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:
+               sys_logger = logging.handlers.SysLogHandler('/dev/log', 'daemon')
+               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)
+       if os.fork() != 0:
+               sys.exit(0)
+
+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
+                       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:
+                       logging.error("Connection died, trying again...")
+                       logging.info("Trying again in 5 seconds.")
+                       sleep(5)
+
+if __name__ == '__main__':
+       options, config_opts = set_stuff_up()
+       while True:
+               try:
+                       logging.info('Starting Vend Server')
+                       do_vend_server(options, config_opts)
+                       logging.warning('Vend Server finished unexpectedly, restarting')
+               except KeyboardInterrupt:
+                       logging.info("Killed by signal, cleaning up")
+                       clean_up_nicely(options, config_opts)
+                       logging.info("Vend Server stopped")
+                       break
+               except:
+                       (exc_type, exc_value, exc_traceback) = sys.exc_info()
+                       tb = format_tb(exc_traceback, 20)
+                       del exc_traceback
+                       
+                       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...)")
+

UCC git Repository :: git.ucc.asn.au