do more logging
[uccvend-vendserver.git] / sql-edition / servers / VendServer.py
1 #!/usr/bin/python
2 # vim:ts=4
3
4 USE_DB = 0
5
6 import ConfigParser
7 import sys, os, string, re, pwd, signal
8 import logging, logging.handlers
9 from traceback import format_tb
10 if USE_DB: import pg
11 from time import time, sleep
12 from popen2 import popen2
13 from LATClient import LATClient, LATClientException
14 from VendingMachine import VendingMachine, VendingException
15 from HorizScroll import HorizScroll
16 from random import random, seed
17 from Idler import TrainIdler,GrayIdler
18 import socket
19 from posix import geteuid
20
21 GREETING = 'UCC SNACKS'
22 PIN_LENGTH = 4
23
24 DOOR = 1
25 SWITCH = 2
26 KEY = 3
27
28 class DispenseDatabase:
29         def __init__(self, vending_machine, host, name, user, password):
30                 self.vending_machine = vending_machine
31                 self.db = pg.DB(dbname = name, host = host, user = user, passwd = password)
32                 self.db.query('LISTEN vend_requests')
33
34         def process_requests(self):
35                 print 'processing'
36                 query = 'SELECT request_id, request_slot FROM vend_requests WHERE request_handled = false'
37                 try:
38                         outstanding = self.db.query(query).getresult()
39                 except (pg.error,), db_err:
40                         sys.stderr.write('Failed to query database: %s\n'%(db_err.strip()))
41                         return
42                 for (id, slot) in outstanding:
43                         (worked, code, string) = self.vending_machine.vend(slot)
44                         print (worked, code, string)
45                         if worked:
46                                 query = 'SELECT vend_success(%s)'%id
47                                 self.db.query(query).getresult()
48                         else:
49                                 query = 'SELECT vend_failed(%s)'%id
50                                 self.db.query(query).getresult()
51
52         def handle_events(self):
53                 notifier = self.db.getnotify()
54                 while notifier is not None:
55                         self.process_requests()
56                         notify = self.db.getnotify()
57
58 def scroll_options(username, mk, welcome = False):
59         if welcome:
60                 msg = [(center('WELCOME'), False, 0.8),
61                            (center(username), False, 0.8)]
62         else:
63                 msg = []
64         choices = ' '*10+'CHOICES: '
65         try:
66                 coke_machine = file('/home/other/coke/coke_contents')
67                 cokes = coke_machine.readlines()
68                 coke_machine.close()
69         except:
70                 cokes = []
71                 pass
72         for c in cokes:
73                 c = c.strip()
74                 (slot_num, price, slot_name) = c.split(' ', 2)
75                 if slot_name == 'dead': continue
76                 choices += '%s8-%s (%sc) '%(slot_num, slot_name, price)
77         choices += '55-DOOR '
78         choices += 'OR A SNACK. '
79         choices += '99 TO READ AGAIN. '
80         choices += 'CHOICE?   '
81         msg.append((choices, False, None))
82         mk.set_messages(msg)
83
84 def get_pin(uid):
85         try:
86                 info = pwd.getpwuid(uid)
87         except KeyError:
88                 return None
89         if info.pw_dir == None: return False
90         pinfile = os.path.join(info.pw_dir, '.pin')
91         try:
92                 s = os.stat(pinfile)
93         except OSError:
94                 return None
95         if s.st_mode & 077:
96                 return None
97         try:
98                 f = file(pinfile)
99         except IOError:
100                 return None
101         pinstr = f.readline()
102         f.close()
103         if not re.search('^'+'[0-9]'*PIN_LENGTH+'$', pinstr):
104                 return None
105         return int(pinstr)
106
107 def has_good_pin(uid):
108         return get_pin(uid) != None
109
110 def verify_user_pin(uid, pin):
111         if get_pin(uid) == pin:
112                 info = pwd.getpwuid(uid)
113                 return info.pw_name
114         else:
115                 return None
116
117 def door_open_mode(v):
118         print "Entering open door mode"
119         v.display("-FEED  ME-")
120         while True:
121                 e = v.next_event()
122                 if e == None: break
123                 (event, params) = e
124                 if event == DOOR:
125                         if params == 1: # door closed
126                                 v.display("-YUM YUM!-")
127                                 sleep(1)
128                                 return
129
130 def cookie(v):
131         seed(time())
132         messages = ['  WASSUP! ', 'PINK FISH ', ' SECRETS ', '  ESKIMO  ', ' FORTUNES ', 'MORE MONEY']
133         choice = int(random()*len(messages))
134         msg = messages[choice]
135         left = range(len(msg))
136         for i in range(len(msg)):
137                 if msg[i] == ' ': left.remove(i)
138         reveal = 1
139         while left:
140                 s = ''
141                 for i in range(0, len(msg)):
142                         if i in left:
143                                 if reveal == 0:
144                                         left.remove(i)
145                                         s += msg[i]
146                                 else:
147                                         s += chr(int(random()*26)+ord('A'))
148                                 reveal += 1
149                                 reveal %= 17
150                         else:
151                                 s += msg[i]
152                 v.display(s)
153
154 def center(str):
155         LEN = 10
156         return ' '*((LEN-len(str))/2)+str
157
158 class MessageKeeper:
159         def __init__(self, vendie):
160                 # Each element of scrolling_message should be a 3-tuple of
161                 # ('message', True/False if it is to be repeated, time to display)
162                 self.scrolling_message = []
163                 self.v = vendie
164                 self.next_update = None
165
166         def set_message(self, string):
167                 self.scrolling_message = [(string, False, None)]
168                 self.update_display(True)
169
170         def set_messages(self, strings):
171                 self.scrolling_message = strings
172                 self.update_display(True)
173
174         def update_display(self, forced = False):
175                 if not forced and self.next_update != None and time() < self.next_update:
176                         return
177                 if len(self.scrolling_message) > 0:
178                         if len(self.scrolling_message[0][0]) > 10:
179                                 (m, r, t) = self.scrolling_message[0]
180                                 a = []
181                                 exp = HorizScroll(m).expand(padding = 0, wraparound = True)
182                                 if t == None:
183                                         t = 0.1
184                                 else:
185                                         t = t / len(exp)
186                                 for x in exp:
187                                         a.append((x, r, t))
188                                 del self.scrolling_message[0]
189                                 self.scrolling_message = a + self.scrolling_message
190                         newmsg = self.scrolling_message[0]
191                         if newmsg[2] != None:
192                                 self.next_update = time() + newmsg[2]
193                         else:
194                                 self.next_update = None
195                         self.v.display(self.scrolling_message[0][0])
196                         if self.scrolling_message[0][1]:
197                                 self.scrolling_message.append(self.scrolling_message[0])
198                         del self.scrolling_message[0]
199
200         def done(self):
201                 return len(self.scrolling_message) == 0
202
203 def run_forever(rfh, wfh, options, cf):
204         v = VendingMachine(rfh, wfh)
205         print 'PING is', v.ping()
206
207         if USE_DB: db = DispenseDatabase(v, cf.DBServer, cf.DBName, cf.DBUser, cf.DBPassword)
208         cur_user = ''
209         cur_pin = ''
210         cur_selection = ''
211
212         mk = MessageKeeper(v)
213         mk.set_message(GREETING)
214         time_to_autologout = None
215         #idler = TrainIdler(v)
216         #idler = GrayIdler(v)
217         idler = GrayIdler(v,one="*",zero="-")
218         time_to_idle = None
219         last_timeout_refresh = None
220
221         while True:
222                 if USE_DB: db.handle_events()
223
224                 if time_to_autologout != None:
225                         time_left = time_to_autologout - time()
226                         if time_left < 6 and (last_timeout_refresh is None or last_timeout_refresh > time_left):
227                                 mk.set_message('LOGOUT: '+str(int(time_left)))
228                                 last_timeout_refresh = int(time_left)
229                                 cur_selection = ''
230
231                 if time_to_autologout != None and time_to_autologout - time() <= 0:
232                         time_to_autologout = None
233                         cur_user = ''
234                         cur_pin = ''
235                         cur_selection = ''
236                         mk.set_message(GREETING)
237
238                 if time_to_autologout and not mk.done(): time_to_autologout = None
239                 if cur_user == '' and time_to_autologout: time_to_autologout = None
240                 if len(cur_pin) == PIN_LENGTH and mk.done() and time_to_autologout == None:
241                         # start autologout
242                         time_to_autologout = time() + 15
243
244                 if time_to_idle == None and cur_user == '': time_to_idle = time() + 60
245                 if time_to_idle != None and cur_user != '': time_to_idle = None
246                 if time_to_idle is not None and time() > time_to_idle: idler.next()
247
248                 mk.update_display()
249
250                 e = v.next_event(0)
251                 if e == None:
252                         e = v.next_event(0.1)
253                         if e == None:
254                                 continue
255                 time_to_idle = None
256                 (event, params) = e
257                 print e
258                 if event == DOOR:
259                         if params == 0:
260                                 door_open_mode(v);
261                                 cur_user = ''
262                                 cur_pin = ''
263                                 mk.set_message(GREETING)
264                 elif event == SWITCH:
265                         # don't care right now.
266                         pass
267                 elif event == KEY:
268                         key = params
269                         # complicated key handling here:
270                         if len(cur_user) < 5:
271                                 if key == 11:
272                                         cur_user = ''
273                                         mk.set_message(GREETING)
274                                         continue
275                                 cur_user += chr(key + ord('0'))
276                                 mk.set_message('UID: '+cur_user)
277                                 if len(cur_user) == 5:
278                                         uid = int(cur_user)
279                                         if not has_good_pin(uid):
280                                                 #mk.set_messages(
281                                                         #[(center('INVALID'), False, 0.7),
282                                                          #(center('PIN'), False, 0.7),
283                                                          #(center('SETUP'), False, 1.0),
284                                                          #(GREETING, False, None)])
285                                                 mk.set_messages(
286                                                         [(' '*10+'INVALID PIN SETUP'+' '*10, False, 3),
287                                                          (GREETING, False, None)])
288                                                 cur_user = ''
289                                                 cur_pin = ''
290                                                 continue
291                                         cur_pin = ''
292                                         mk.set_message('PIN: ')
293                                         continue
294                         elif len(cur_pin) < PIN_LENGTH:
295                                 if key == 11:
296                                         if cur_pin == '':
297                                                 cur_user = ''
298                                                 mk.set_message(GREETING)
299                                                 continue
300                                         cur_pin = ''
301                                         mk.set_message('PIN: ')
302                                         continue
303                                 cur_pin += chr(key + ord('0'))
304                                 mk.set_message('PIN: '+'X'*len(cur_pin))
305                                 if len(cur_pin) == PIN_LENGTH:
306                                         username = verify_user_pin(int(cur_user), int(cur_pin))
307                                         if username:
308                                                 v.beep(0, False)
309                                                 cur_selection = ''
310                                                 scroll_options(username, mk, True)
311                                                 continue
312                                         else:
313                                                 v.beep(40, False)
314                                                 mk.set_messages(
315                                                         [(center('BAD PIN'), False, 1.0),
316                                                          (center('SORRY'), False, 0.5),
317                                                          (GREETING, False, None)])
318                                                 cur_user = ''
319                                                 cur_pin = ''
320                                                 continue
321                         elif len(cur_selection) == 0:
322                                 if key == 11:
323                                         cur_pin = ''
324                                         cur_user = ''
325                                         cur_selection = ''
326                                         mk.set_messages(
327                                                 [(center('BYE!'), False, 1.5),
328                                                  (GREETING, False, None)])
329                                         continue
330                                 cur_selection += chr(key + ord('0'))
331                                 mk.set_message('SELECT: '+cur_selection)
332                                 time_to_autologout = None
333                         elif len(cur_selection) == 1:
334                                 if key == 11:
335                                         cur_selection = ''
336                                         time_to_autologout = None
337                                         scroll_options(username, mk)
338                                         continue
339                                 else:
340                                         cur_selection += chr(key + ord('0'))
341                                         #make_selection(cur_selection)
342                                         # XXX this should move somewhere else:
343                                         if cur_selection == '55':
344                                                 mk.set_message('OPENSESAME')
345                                                 if geteuid() == 0:
346                                                         ret = os.system('su - "%s" -c "dispense door"'%username)
347                                                 else:
348                                                         ret = os.system('dispense door')
349                                                 if ret == 0:
350                                                         mk.set_message(center('DOOR OPEN'))
351                                                 else:
352                                                         mk.set_message(center('BAD DOOR'))
353                                                 sleep(1)
354                                         elif cur_selection == '91':
355                                                 cookie(v)
356                                         elif cur_selection == '99':
357                                                 scroll_options(username, mk)
358                                                 cur_selection = ''
359                                                 continue
360                                         elif cur_selection[1] == '8':
361                                                 v.display('GOT COKE?')
362                                                 os.system('su - "%s" -c "dispense %s"'%(username, cur_selection[0]))
363                                         else:
364                                                 v.display('HERES A '+cur_selection)
365                                                 v.vend(cur_selection)
366                                         sleep(0.5)
367                                         v.display('THANK YOU')
368                                         sleep(0.5)
369                                         cur_selection = ''
370                                         time_to_autologout = time() + 8
371
372 def connect_to_vend(options, cf):
373         # Open vending machine via LAT?
374         if options.use_lat:
375                 latclient = LATClient(service = cf.ServiceName, password = cf.ServicePassword, server_name = cf.ServerName, connect_password = cf.ConnectPassword, priv_password = cf.PrivPassword)
376                 rfh, wfh = latclient.get_fh()
377         else:
378                 #(rfh, wfh) = popen2('../../virtualvend/vvend.py')
379                 import socket
380                 sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM, 0)
381                 sock.connect((options.host, options.port))
382                 rfh = sock.makefile('r')
383                 wfh = sock.makefile('w')
384                 
385         return rfh, wfh
386
387 def parse_args():
388         from optparse import OptionParser
389
390         op = OptionParser(usage="%prog [OPTION]...")
391         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')
392         op.add_option('--virtualvend', action='store_false', default=True, dest='use_lat', help='use the virtual vending server instead of LAT')
393         op.add_option('-n', '--hostname', dest='host', default='localhost', help='the hostname to connect to for virtual vending machine mode (default: localhost)')
394         op.add_option('-p', '--port', dest='port', default=5150, type='int', help='the port number to connect to (default: 5150)')
395         op.add_option('-l', '--log-file', metavar='FILE', dest='log_file', default='', help='log output to the specified file')
396         op.add_option('-s', '--syslog', dest='syslog', action='store_true', default=False, help='log output to syslog')
397         op.add_option('-d', '--daemon', dest='daemon', action='store_true', default=False, help='run as a daemon')
398         op.add_option('-v', '--verbose', dest='verbose', action='store_true', default=False, help='spit out lots of debug output')
399         op.add_option('--pid-file', dest='pid_file', metavar='FILE', default='', help='store daemon\'s pid in the given file')
400         options, args = op.parse_args()
401
402         if len(args) != 0:
403                 op.error('extra command line arguments: ' + ' '.join(args))
404
405         return options
406
407 config_options = {
408         'DBServer': ('Database', 'Server'),
409         'DBName': ('Database', 'Name'),
410         'DBUser': ('VendingMachine', 'DBUser'),
411         'DBPassword': ('VendingMachine', 'DBPassword'),
412         
413         'ServiceName': ('VendingMachine', 'ServiceName'),
414         'ServicePassword': ('VendingMachine', 'Password'),
415         
416         'ServerName': ('DecServer', 'Name'),
417         'ConnectPassword': ('DecServer', 'ConnectPassword'),
418         'PrivPassword': ('DecServer', 'PrivPassword'),
419         }
420
421 class VendConfigFile:
422         def __init__(self, config_file, options):
423                 try:
424                         cp = ConfigParser.ConfigParser()
425                         cp.read(config_file)
426
427                         for option in options:
428                                 section, name = options[option]
429                                 value = cp.get(section, name)
430                                 self.__dict__[option] = value
431                 
432                 except ConfigParser.Error, e:
433                         print "Error reading config file "+config_file+": " + str(e)
434                         sys.exit(1)
435
436 def create_pid_file(name):
437         try:
438                 pid_file = file(name, 'w')
439                 pid_file.write('%d\n'%os.getpid())
440                 pid_file.close()
441         except IOError, e:
442                 logging.warning('unable to write to pid file '+name+': '+str(e))
443
444 def set_stuff_up():
445         def do_nothing(signum, stack):
446                 signal.signal(signum, do_nothing)
447         def stop_server(signum, stack): raise KeyboardInterrupt
448         signal.signal(signal.SIGHUP, do_nothing)
449         signal.signal(signal.SIGTERM, stop_server)
450         signal.signal(signal.SIGINT, stop_server)
451
452         options = parse_args()
453         config_opts = VendConfigFile(options.config_file, config_options)
454         if options.daemon: become_daemon()
455         set_up_logging(options)
456         if options.pid_file != '': create_pid_file(options.pid_file)
457
458         return options, config_opts
459
460 def clean_up_nicely(options, config_opts):
461         if options.pid_file != '':
462                 try:
463                         os.unlink(options.pid_file)
464                         logging.debug('Removed pid file '+options.pid_file)
465                 except OSError: pass  # if we can't delete it, meh
466
467 def set_up_logging(options):
468         logger = logging.getLogger()
469         
470         stderr_logger = logging.StreamHandler(sys.stderr)
471         stderr_logger.setFormatter(logging.Formatter('%(levelname)s: %(message)s'))
472         logger.addHandler(stderr_logger)
473         
474         if options.log_file != '':
475                 try:
476                         file_logger = logging.FileHandler(options.log_file)
477                         file_logger.setFormatter(logging.Formatter('%(asctime)s %(levelname)s: %(message)s'))
478                         logger.addHandler(file_logger)
479                 except IOError, e:
480                         logger.warning('unable to write to log file '+options.log_file+': '+str(e))
481
482         if options.syslog:
483                 sys_logger = logging.handlers.SysLogHandler('/dev/log', 'daemon')
484                 sys_logger.setFormatter(logging.Formatter('vendserver[%d]'%(os.getpid()) + ' %(levelname)s: %(message)s'))
485                 logger.addHandler(sys_logger)
486         
487         if options.verbose:
488                 logger.setLevel(logging.DEBUG)
489         else:
490                 logger.setLevel(logging.INFO)
491
492 def become_daemon():
493         dev_null = file('/dev/null')
494         fd = dev_null.fileno()
495         os.dup2(fd, 0)
496         os.dup2(fd, 1)
497         os.dup2(fd, 2)
498         if os.fork() != 0:
499                 sys.exit(0)
500
501 def do_vend_server(options, config_opts):
502         while True:
503                 try:
504                         rfh, wfh = connect_to_vend(options, config_opts)
505                 except (LATClientException, socket.error), e:
506                         (exc_type, exc_value, exc_traceback) = sys.exc_info()
507                         del exc_traceback
508                         logging.error("Connection error: "+str(exc_type)+" "+str(e))
509                         logging.info("Trying again in 5 seconds.")
510                         sleep(5)
511                         continue
512                 
513                 try:
514                         run_forever(rfh, wfh, options, config_opts)
515                 except VendingException:
516                         logging.error("Connection died, trying again...")
517                         logging.info("Trying again in 5 seconds.")
518                         sleep(5)
519
520 if __name__ == '__main__':
521         options, config_opts = set_stuff_up()
522         while True:
523                 try:
524                         logging.info('Starting Vend Server')
525                         do_vend_server(options, config_opts)
526                         logging.warning('Vend Server finished unexpectedly, restarting')
527                 except KeyboardInterrupt:
528                         logging.info("Killed by signal, cleaning up")
529                         clean_up_nicely(options, config_opts)
530                         logging.info("Vend Server stopped")
531                         break
532                 except:
533                         (exc_type, exc_value, exc_traceback) = sys.exc_info()
534                         tb = format_tb(exc_traceback, 20)
535                         del exc_traceback
536                         
537                         logging.critical("Uh-oh, unhandled " + str(exc_type) + " exception")
538                         logging.critical("Message: " + str(exc_value))
539                         logging.critical("Traceback:")
540                         for event in tb:
541                                 for line in event.split('\n'):
542                                         logging.critical('    '+line)
543                         logging.critical("This message should be considered a bug in the Vend Server.")
544                         logging.critical("Please report this to someone who can fix it.")
545                         sleep(10)
546                         logging.warning("Trying again anyway (might not help, but hey...)")
547

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