VendServer/VendServer.py

   1 #!/usr/bin/python
   2 # vim:ts=4
   3
   4 USE_DB = 0
   5 USE_MIFARE = 1
   6
   7 import ConfigParser
   8 import sys, os, string, re, pwd, signal, math, syslog
   9 import logging, logging.handlers
  10 from traceback import format_tb
  11 if USE_DB: import pg
  12 from time import time, sleep, mktime, localtime
  13 from subprocess import Popen, PIPE
  14 from LATClient import LATClient, LATClientException
  15 from SerialClient import SerialClient, SerialClientException
  16 from VendingMachine import VendingMachine, VendingException
  17 from MessageKeeper import MessageKeeper
  18 from HorizScroll import HorizScroll
  19 from random import random, seed
  20 from Idler import GreetingIdler,TrainIdler,GrayIdler,StringIdler,ClockIdler,FortuneIdler,FileIdler,PipeIdler
  21 from SnackConfig import get_snack#, get_snacks
  22 import socket
  23 from posix import geteuid
  24 from LDAPConnector import get_uid,get_uname, set_card_id
  25 from OpenDispense import OpenDispense as Dispense
  26
  27 CREDITS="""
  28 This vending machine software brought to you by:
  29 Bernard Blackham
  30 Mark Tearle
  31 Nick Bannon
  32 Cameron Patrick
  33 and a collective of hungry alpacas.
  34
  35 The MIFARE card reader bought to you by:
  36 David Adam
  37
  38 Bug Hunting and hardware maintenance by:
  39 Mitchell Pomery
  40
  41 For a good time call +61 8 6488 3901
  42
  43
  44
  45 """
  46
  47 PIN_LENGTH = 4
  48
  49 DOOR = 1
  50 SWITCH = 2
  51 KEY = 3
  52 TICK = 4
  53 MIFARE = 5
  54
  55
  56 (
  57 STATE_IDLE,
  58 STATE_DOOR_OPENING,
  59 STATE_DOOR_CLOSING,
  60 STATE_GETTING_UID,
  61 STATE_GETTING_PIN,
  62 STATE_GET_SELECTION,
  63 STATE_GRANDFATHER_CLOCK,
  64 ) = range(1,8)
  65
  66 TEXT_SPEED = 0.8
  67 IDLE_SPEED = 0.05
  68
  69 _pin_uid = 0
  70 _pin_uname = 'root'
  71 _pin_pin = '----'
  72
  73 _last_card_id = -1
  74
  75 idlers = []
  76 idler = None
  77
  78
  79 class DispenseDatabaseException(Exception): pass
  80
  81 class DispenseDatabase:
  82         def __init__(self, vending_machine, host, name, user, password):
  83                 self.vending_machine = vending_machine
  84                 self.db = pg.DB(dbname = name, host = host, user = user, passwd = password)
  85                 self.db.query('LISTEN vend_requests')
  86
  87         def process_requests(self):
  88                 logging.debug('database processing')
  89                 query = 'SELECT request_id, request_slot FROM vend_requests WHERE request_handled = false'
  90                 try:
  91                         outstanding = self.db.query(query).getresult()
  92                 except (pg.error,), db_err:
  93                         raise DispenseDatabaseException('Failed to query database: %s\n'%(db_err.strip()))
  94                 for (id, slot) in outstanding:
  95                         (worked, code, string) = self.vending_machine.vend(slot)
  96                         logging.debug (str((worked, code, string)))
  97                         if worked:
  98                                 query = 'SELECT vend_success(%s)'%id
  99                                 self.db.query(query).getresult()
 100                         else:
 101                                 query = 'SELECT vend_failed(%s)'%id
 102                                 self.db.query(query).getresult()
 103
 104         def handle_events(self):
 105                 notifier = self.db.getnotify()
 106                 while notifier is not None:
 107                         self.process_requests()
 108                         notify = self.db.getnotify()
 109
 110 class VendState:
 111         def __init__(self,v):
 112                 self.state_table = {}
 113                 self.state = STATE_IDLE
 114                 self.counter = 0
 115
 116                 self.mk = MessageKeeper(v)
 117                 self.cur_user = ''
 118                 self.cur_pin = ''
 119                 self.username = ''
 120                 self.cur_selection = ''
 121                 self.time_to_autologout = None
 122
 123                 self.last_timeout_refresh = None
 124
 125         def change_state(self,newstate,newcounter=None):
 126                 if self.state != newstate:
 127                         #print "Changing state from: ",
 128                         #print self.state,
 129                         #print " to ",
 130                         #print newstate
 131                         self.state = newstate
 132
 133                 if newcounter is not None and self.counter != newcounter:
 134                         #print "Changing counter from: ",
 135                         #print self.counter,
 136                         #print " to ",
 137                         #print newcounter
 138                         self.counter = newcounter
 139
 140
 141
 142 def scroll_options(username, mk, welcome = False):
 143         if welcome:
 144                 # Balance checking
 145                 acct, unused = Popen(['dispense', 'acct', username], close_fds=True, stdout=PIPE).communicate()
 146                 # this is fucking appalling
 147                 balance = acct[acct.find("$")+1:acct.find("(")].strip()
 148
 149                 msg = [(center('WELCOME'), False, TEXT_SPEED),
 150                            (center(username), False, TEXT_SPEED),
 151                            (center(balance), False, TEXT_SPEED),]
 152         else:
 153                 msg = []
 154         choices = ' '*10+'CHOICES: '
 155
 156         # Get coke contents
 157         cokes = []
 158         for i in range(0, 7):
 159                 args = ('dispense', 'iteminfo', 'coke:%i' % i)
 160                 info, unused = Popen(args, close_fds=True, stdout=PIPE).communicate()
 161                 m = re.match("\s*[a-z]+:\d+\s+(\d+)\.(\d\d)\s+([^\n]+)", info)
 162                 cents = int(m.group(1))*100 + int(m.group(2))
 163                 cokes.append('%i %i %s' % (i, cents, m.group(3)));
 164
 165         for c in cokes:
 166                 c = c.strip()
 167                 (slot_num, price, slot_name) = c.split(' ', 2)
 168                 if slot_name == 'dead': continue
 169                 choices += '%s-(%sc)-%s8 '%(slot_name, price, slot_num)
 170
 171 #       we don't want to print snacks for now since it'll be too large
 172 #       and there's physical bits of paper in the machine anyway - matt
 173 #       try:
 174 #               snacks = get_snacks()
 175 #       except:
 176 #               snacks = {}
 177 #
 178 #       for slot, ( name, price ) in snacks.items():
 179 #               choices += '%s8-%s (%sc) ' % ( slot, name, price )
 180
 181         choices += '55-DOOR '
 182         choices += 'OR ANOTHER SNACK. '
 183         choices += '99 TO READ AGAIN. '
 184         choices += 'CHOICE?   '
 185         msg.append((choices, False, None))
 186         mk.set_messages(msg)
 187
 188 def _check_pin(uid, pin):
 189         global _pin_uid
 190         global _pin_uname
 191         global _pin_pin
 192         print "_check_pin('",uid,"',---)"
 193         if uid != _pin_uid:
 194                 try:
 195                         info = pwd.getpwuid(uid)
 196                 except KeyError:
 197                         logging.info('getting pin for uid %d: user not in password file'%uid)
 198                         return None
 199                 if info.pw_dir == None: return False
 200                 pinfile = os.path.join(info.pw_dir, '.pin')
 201                 try:
 202                         s = os.stat(pinfile)
 203                 except OSError:
 204                         logging.info('getting pin for uid %d: .pin not found in home directory'%uid)
 205                         return None
 206                 if s.st_mode & 077:
 207                         logging.info('getting pin for uid %d: .pin has wrong permissions. Fixing.'%uid)
 208                         os.chmod(pinfile, 0600)
 209                 try:
 210                         f = file(pinfile)
 211                 except IOError:
 212                         logging.info('getting pin for uid %d: I cannot read pin file'%uid)
 213                         return None
 214                 pinstr = f.readline()
 215                 f.close()
 216                 if not re.search('^'+'[0-9]'*PIN_LENGTH+'$', pinstr):
 217                         logging.info('getting pin for uid %d: %s not a good pin'%(uid,repr(pinstr)))
 218                         return None
 219                 _pin_uid = uid
 220                 _pin_pin = pinstr
 221                 _pin_uname = info.pw_name
 222         else:
 223                 pinstr = _pin_pin
 224         if pin == int(pinstr):
 225                 logging.info("Pin correct for %d",uid)
 226         else:
 227                 logging.info("Pin incorrect for %d",uid)
 228         return pin == int(pinstr)
 229
 230 def acct_is_disabled(name=None):
 231         global _pin_uname
 232         if name == None:
 233                 name = _pin_uname
 234         acct, unused = Popen(['dispense', 'acct', _pin_uname], close_fds=True, stdout=PIPE).communicate()
 235         # this is fucking appalling
 236         flags = acct[acct.find("(")+1:acct.find(")")].strip()
 237         if 'disabled' in flags:
 238                 return True
 239         if 'internal' in flags:
 240                 return True
 241         return False
 242
 243 def has_good_pin(uid):
 244         return _check_pin(uid, None) != None
 245
 246 def verify_user_pin(uid, pin, skip_pin_check=False):
 247         if skip_pin_check or _check_pin(uid, pin) == True:
 248                 info = pwd.getpwuid(uid)
 249                 if skip_pin_check:
 250                         if acct_is_disabled(info.pw_name):
 251                                 logging.info('refused mifare for disabled acct uid %d (%s)'%(uid,info.pw_name))
 252                                 return '-disabled-'
 253                         logging.info('accepted mifare for uid %d (%s)'%(uid,info.pw_name))
 254                 else:
 255                         logging.info('accepted pin for uid %d (%s)'%(uid,info.pw_name))
 256                 return info.pw_name
 257         else:
 258                 logging.info('refused pin for uid %d'%(uid))
 259                 return None
 260
 261
 262 def cookie(v):
 263         seed(time())
 264         messages = ['  WASSUP! ', 'PINK FISH ', ' SECRETS ', '  ESKIMO  ', ' FORTUNES ', 'MORE MONEY']
 265         choice = int(random()*len(messages))
 266         msg = messages[choice]
 267         left = range(len(msg))
 268         for i in range(len(msg)):
 269                 if msg[i] == ' ': left.remove(i)
 270         reveal = 1
 271         while left:
 272                 s = ''
 273                 for i in range(0, len(msg)):
 274                         if i in left:
 275                                 if reveal == 0:
 276                                         left.remove(i)
 277                                         s += msg[i]
 278                                 else:
 279                                         s += chr(int(random()*26)+ord('A'))
 280                                 reveal += 1
 281                                 reveal %= 17
 282                         else:
 283                                 s += msg[i]
 284                 v.display(s)
 285
 286 def center(str):
 287         LEN = 10
 288         return ' '*((LEN-len(str))/2)+str
 289
 290 def setup_idlers(v):
 291         global idlers, idler
 292         idlers = [
 293                 #
 294                 GrayIdler(v),
 295                 GrayIdler(v,one="*",zero="-"),
 296                 GrayIdler(v,one="/",zero="\\"),
 297                 GrayIdler(v,one="X",zero="O"),
 298                 GrayIdler(v,one="*",zero="-",reorder=1),
 299                 GrayIdler(v,one="/",zero="\\",reorder=1),
 300                 GrayIdler(v,one="X",zero="O",reorder=1),
 301                 #
 302                 ClockIdler(v),
 303                 ClockIdler(v),
 304                 ClockIdler(v),
 305                 #
 306                 StringIdler(v), # Hello Cruel World
 307                 StringIdler(v, text="Kill 'em all", repeat=False),
 308                 StringIdler(v, text=CREDITS),
 309                 StringIdler(v, text=str(math.pi) + "            "),
 310                 StringIdler(v, text=str(math.e) + "            "),
 311                 StringIdler(v, text="    I want some pizza - please call Broadway Pizza on +61 8 9389 8500 - and order as Quinn - I am getting really hungry", repeat=False),
 312                 # "Hello World" in brainfuck
 313                 StringIdler(v, text=">+++++++++[<++++++++>-]<.>+++++++[<++++>-]<+.+++++++..+++.[-]>++++++++[<++++>-] <.>+++++++++++[<++++++++>-]<-.--------.+++.------.--------.[-]>++++++++[<++++>- ]<+.[-]++++++++++."),
 314                 #
 315                 TrainIdler(v),
 316                 #
 317                 FileIdler(v, '/usr/share/common-licenses/GPL-2',affinity=2),
 318                 #
 319                 PipeIdler(v, "/usr/bin/getent", "passwd"),
 320                 FortuneIdler(v,affinity=20),
 321                 ]
 322         disabled = [
 323                 ]
 324
 325 def reset_idler(v, vstatus, t = None):
 326         global idlers, idler
 327         idler = GreetingIdler(v, t)
 328         vstatus.time_of_next_idlestep = time()+idler.next()
 329         vstatus.time_of_next_idler = None
 330         vstatus.time_to_autologout = None
 331         vstatus.change_state(STATE_IDLE, 1)
 332
 333 def choose_idler():
 334         global idlers, idler
 335
 336         # Implementation of the King Of the Hill algorithm from;
 337         # http://eli.thegreenplace.net/2010/01/22/weighted-random-generation-in-python/
 338
 339         #def weighted_choice_king(weights):
 340         #       total = 0
 341         #       winner = 0
 342         #       for i, w in enumerate(weights):
 343         #               total += w
 344         #               if random.random() * total < w:
 345         #                       winner = i
 346         #       return winner
 347         #
 348
 349         total = 0
 350         winner = None
 351
 352         for choice in idlers:
 353                 weight = choice.affinity()
 354                 total += weight
 355                 if random() * total < weight:
 356                         winner = choice
 357
 358         idler = winner
 359
 360         if idler:
 361                 idler.reset()
 362
 363 def idle_step(vstatus):
 364         global idler
 365         if idler.finished():
 366                 choose_idler()
 367                 vstatus.time_of_next_idler = time() + 30
 368         nextidle = idler.next()
 369         if nextidle is None:
 370                 nextidle = IDLE_SPEED
 371         vstatus.time_of_next_idlestep = time()+nextidle
 372
 373
 374
 375 def handle_tick_event(event, params, v, vstatus):
 376         # don't care right now.
 377         pass
 378
 379 def handle_switch_event(event, params, v, vstatus):
 380         # don't care right now.
 381         pass
 382
 383
 384 def do_nothing(state, event, params, v, vstatus):
 385         print "doing nothing (s,e,p)", state, " ", event, " ", params
 386         pass
 387
 388 def handle_getting_uid_idle(state, event, params, v, vstatus):
 389         # don't care right now.
 390         pass
 391
 392 def handle_getting_pin_idle(state, event, params, v, vstatus):
 393         # don't care right now.
 394         pass
 395
 396 def handle_get_selection_idle(state, event, params, v, vstatus):
 397         global _last_card_id
 398         # don't care right now.
 399         ###
 400         ### State logging out ..
 401         if vstatus.time_to_autologout != None:
 402                 time_left = vstatus.time_to_autologout - time()
 403                 if time_left < 6 and (vstatus.last_timeout_refresh is None or vstatus.last_timeout_refresh > time_left):
 404                         vstatus.mk.set_message('LOGOUT: '+str(int(time_left)))
 405                         vstatus.last_timeout_refresh = int(time_left)
 406                         vstatus.cur_selection = ''
 407
 408         if vstatus.time_to_autologout != None and vstatus.time_to_autologout - time() <= 0:
 409                 vstatus.time_to_autologout = None
 410                 vstatus.cur_user = ''
 411                 vstatus.cur_pin = ''
 412                 vstatus.cur_selection = ''
 413                 _last_card_id = -1
 414                 reset_idler(v, vstatus)
 415
 416         ### State fully logged out ... reset variables
 417         if vstatus.time_to_autologout and not vstatus.mk.done():
 418                 vstatus.time_to_autologout = None
 419         if vstatus.cur_user == '' and vstatus.time_to_autologout:
 420                 vstatus.time_to_autologout = None
 421
 422         ### State logged in
 423         if len(vstatus.cur_pin) == PIN_LENGTH and vstatus.mk.done() and vstatus.time_to_autologout == None:
 424                 # start autologout
 425                 vstatus.time_to_autologout = time() + 15
 426                 vstatus.last_timeout_refresh = None
 427
 428         ## FIXME - this may need to be elsewhere.....
 429         # need to check
 430         vstatus.mk.update_display()
 431
 432
 433
 434 def handle_get_selection_key(state, event, params, v, vstatus):
 435         global _last_card_id
 436         key = params
 437         if len(vstatus.cur_selection) == 0:
 438                 if key == 11:
 439                         vstatus.cur_pin = ''
 440                         vstatus.cur_user = ''
 441                         vstatus.cur_selection = ''
 442                         _last_card_id = -1
 443                         vstatus.mk.set_messages([(center('BYE!'), False, 1.5)])
 444                         reset_idler(v, vstatus, 2)
 445                         return
 446                 vstatus.cur_selection += chr(key + ord('0'))
 447                 vstatus.mk.set_message('SELECT: '+vstatus.cur_selection)
 448                 vstatus.time_to_autologout = None
 449         elif len(vstatus.cur_selection) == 1:
 450                 if key == 11:
 451                         vstatus.cur_selection = ''
 452                         vstatus.time_to_autologout = None
 453                         scroll_options(vstatus.username, vstatus.mk)
 454                         return
 455                 else:
 456                         vstatus.cur_selection += chr(key + ord('0'))
 457                         if vstatus.cur_user:
 458                                 make_selection(v,vstatus)
 459                                 vstatus.cur_selection = ''
 460                                 vstatus.time_to_autologout = time() + 8
 461                                 vstatus.last_timeout_refresh = None
 462                         else:
 463                                 # Price check mode.
 464                                 price_check(v,vstatus)
 465                                 vstatus.cur_selection = ''
 466                                 vstatus.time_to_autologout = None
 467                                 vstatus.last_timeout_refresh = None
 468
 469 def make_selection(v, vstatus):
 470         # should use sudo here
 471         if vstatus.cur_selection == '55':
 472                 vstatus.mk.set_message('OPENSESAME')
 473                 logging.info('dispensing a door for %s'%vstatus.username)
 474                 if geteuid() == 0:
 475                         #ret = os.system('su - "%s" -c "dispense door"'%vstatus.username)
 476                         ret = os.system('dispense -u "%s" door'%vstatus.username)
 477                 else:
 478                         ret = os.system('dispense door')
 479                 if ret == 0:
 480                         logging.info('door opened')
 481                         vstatus.mk.set_message(center('DOOR OPEN'))
 482                 else:
 483                         logging.warning('user %s tried to dispense a bad door'%vstatus.username)
 484                         vstatus.mk.set_message(center('BAD DOOR'))
 485                 sleep(1)
 486         elif vstatus.cur_selection == '81':
 487                 cookie(v)
 488         elif vstatus.cur_selection == '99':
 489                 scroll_options(vstatus.username, vstatus.mk)
 490                 vstatus.cur_selection = ''
 491                 return
 492         elif vstatus.cur_selection[1] == '8':
 493                 v.display('GOT DRINK?')
 494                 if ((os.system('dispense -u "%s" coke:%s'%(vstatus.username, vstatus.cur_selection[0])) >> 8) != 0):
 495                         v.display('SEEMS NOT')
 496                 else:
 497                         v.display('GOT DRINK!')
 498         else:
 499                 # first see if it's a named slot
 500                 try:
 501                         price, shortname, name = get_snack( vstatus.cur_selection )
 502                 except:
 503                         price, shortname, name = get_snack( '--' )
 504                 dollarprice = "$%.2f" % ( price / 100.0 )
 505                 v.display(vstatus.cur_selection+' - %s'%dollarprice)
 506 #               exitcode = os.system('dispense -u "%s" give \>snacksales %d "%s"'%(vstatus.username, price, name)) >> 8
 507 #               exitcode = os.system('dispense -u "%s" give \>sales\:snack %d "%s"'%(vstatus.username, price, name)) >> 8
 508                 exitcode = os.system('dispense -u "%s" snack:%s'%(vstatus.username, vstatus.cur_selection)) >> 8
 509                 if (exitcode == 0):
 510                         # magic dispense syslog service
 511                         syslog.syslog(syslog.LOG_INFO | syslog.LOG_LOCAL4, "vended %s (slot %s) for %s" % (name, vstatus.cur_selection, vstatus.username))
 512                         (worked, code, string) = v.vend(vstatus.cur_selection)
 513                         if worked:
 514                                 v.display('THANK YOU')
 515                         else:
 516                                 print "Vend Failed:", code, string
 517                                 v.display('VEND FAIL')
 518                 elif (exitcode == 5):   # RV_BALANCE
 519                         v.display('NO MONEY?')
 520                 elif (exitcode == 4):   # RV_ARGUMENTS (zero give causes arguments)
 521                         v.display('EMPTY SLOT')
 522                 elif (exitcode == 1):   # RV_BADITEM (Dead slot)
 523                         v.display('EMPTY SLOT')
 524                 else:
 525                         syslog.syslog(syslog.LOG_INFO | syslog.LOG_LOCAL4, "failed vending %s (slot %s) for %s (code %d)" % (name, vstatus.cur_selection, vstatus.username, exitcode))
 526                         v.display('UNK ERROR')
 527         sleep(1)
 528
 529
 530 def price_check(v, vstatus):
 531         if vstatus.cur_selection[1] == '8':
 532                 args = ('dispense', 'iteminfo', 'coke:' + vstatus.cur_selection[0])
 533                 info, unused = Popen(args, close_fds=True, stdout=PIPE).communicate()
 534                 dollarprice = re.match("\s*[a-z]+:\d+\s+(\d+\.\d\d)\s+([^\n]+)", info).group(1)
 535         else:
 536                 # first see if it's a named slot
 537                 try:
 538                         price, shortname, name = get_snack( vstatus.cur_selection )
 539                 except:
 540                         price, shortname, name = get_snack( '--' )
 541                 dollarprice = "$%.2f" % ( price / 100.0 )
 542         v.display(vstatus.cur_selection+' - %s'%dollarprice)
 543
 544
 545 def handle_getting_pin_key(state, event, params, v, vstatus):
 546         #print "handle_getting_pin_key (s,e,p)", state, " ", event, " ", params
 547         key = params
 548         if len(vstatus.cur_pin) < PIN_LENGTH:
 549                 if key == 11:
 550                         if vstatus.cur_pin == '':
 551                                 vstatus.cur_user = ''
 552                                 reset_idler(v, vstatus)
 553
 554                                 return
 555                         vstatus.cur_pin = ''
 556                         vstatus.mk.set_message('PIN: ')
 557                         return
 558                 vstatus.cur_pin += chr(key + ord('0'))
 559                 vstatus.mk.set_message('PIN: '+'X'*len(vstatus.cur_pin))
 560                 if len(vstatus.cur_pin) == PIN_LENGTH:
 561                         vstatus.username = verify_user_pin(int(vstatus.cur_user), int(vstatus.cur_pin))
 562                         if vstatus.username:
 563                                 v.beep(0, False)
 564                                 vstatus.cur_selection = ''
 565                                 vstatus.change_state(STATE_GET_SELECTION)
 566                                 scroll_options(vstatus.username, vstatus.mk, True)
 567                                 return
 568                         else:
 569                                 v.beep(40, False)
 570                                 vstatus.mk.set_messages(
 571                                         [(center('BAD PIN'), False, 1.0),
 572                                          (center('SORRY'), False, 0.5)])
 573                                 vstatus.cur_user = ''
 574                                 vstatus.cur_pin = ''
 575
 576                                 reset_idler(v, vstatus, 2)
 577
 578                                 return
 579
 580
 581 def handle_getting_uid_key(state, event, params, v, vstatus):
 582         #print "handle_getting_uid_key (s,e,p)", state, " ", event, " ", params
 583         key = params
 584
 585         # complicated key handling here:
 586
 587         if len(vstatus.cur_user) == 0 and key == 9:
 588                 vstatus.cur_selection = ''
 589                 vstatus.time_to_autologout = None
 590                 vstatus.mk.set_message('PRICECHECK')
 591                 sleep(0.5)
 592                 scroll_options('', vstatus.mk)
 593                 vstatus.change_state(STATE_GET_SELECTION)
 594                 return
 595
 596         if len(vstatus.cur_user) <8:
 597                 if key == 11:
 598                         vstatus.cur_user = ''
 599
 600                         reset_idler(v, vstatus)
 601                         return
 602                 vstatus.cur_user += chr(key + ord('0'))
 603                 #logging.info('dob: '+vstatus.cur_user)
 604                 if len(vstatus.cur_user) > 5:
 605                         vstatus.mk.set_message('>'+vstatus.cur_user)
 606                 else:
 607                         vstatus.mk.set_message('UID: '+vstatus.cur_user)
 608
 609         if len(vstatus.cur_user) == 5:
 610                 uid = int(vstatus.cur_user)
 611
 612                 if uid == 0:
 613                         logging.info('user '+vstatus.cur_user+' has a bad PIN')
 614                         pfalken="""
 615 CARRIER DETECTED
 616
 617 CONNECT 128000
 618
 619 Welcome to Picklevision Sytems, Sunnyvale, CA
 620
 621 Greetings Professor Falken.
 622
 623
 624
 625
 626 Shall we play a game?
 627
 628
 629 Please choose from the following menu:
 630
 631 1. Tic-Tac-Toe
 632 2. Chess
 633 3. Checkers
 634 4. Backgammon
 635 5. Poker
 636 6. Toxic and Biochemical Warfare
 637 7. Global Thermonuclear War
 638
 639 7 [ENTER]
 640
 641 Wouldn't you prefer a nice game of chess?
 642
 643 """.replace('\n','    ')
 644                         vstatus.mk.set_messages([(pfalken, False, 10)])
 645                         vstatus.cur_user = ''
 646                         vstatus.cur_pin = ''
 647
 648                         reset_idler(v, vstatus, 10)
 649
 650                         return
 651
 652                 if not has_good_pin(uid):
 653                         logging.info('user '+vstatus.cur_user+' has a bad PIN')
 654                         vstatus.mk.set_messages(
 655                                 [(' '*10+'INVALID PIN SETUP'+' '*11, False, 3)])
 656                         vstatus.cur_user = ''
 657                         vstatus.cur_pin = ''
 658
 659                         reset_idler(v, vstatus, 3)
 660
 661                         return
 662
 663                 if acct_is_disabled():
 664                         logging.info('user '+vstatus.cur_user+' is disabled')
 665                         vstatus.mk.set_messages(
 666                                 [(' '*11+'ACCOUNT DISABLED'+' '*11, False, 3)])
 667                         vstatus.cur_user = ''
 668                         vstatus.cur_pin = ''
 669
 670                         reset_idler(v, vstatus, 3)
 671                         return
 672
 673
 674                 vstatus.cur_pin = ''
 675                 vstatus.mk.set_message('PIN: ')
 676                 logging.info('need pin for user %s'%vstatus.cur_user)
 677                 vstatus.change_state(STATE_GETTING_PIN)
 678                 return
 679
 680
 681 def handle_idle_key(state, event, params, v, vstatus):
 682         #print "handle_idle_key (s,e,p)", state, " ", event, " ", params
 683
 684         key = params
 685
 686         if key == 11:
 687                 vstatus.cur_user = ''
 688                 reset_idler(v, vstatus)
 689                 return
 690
 691         vstatus.change_state(STATE_GETTING_UID)
 692         run_handler(event, key, v, vstatus)
 693
 694
 695 def handle_idle_tick(state, event, params, v, vstatus):
 696         ### State idling
 697         if vstatus.mk.done():
 698                 idle_step(vstatus)
 699
 700         if vstatus.time_of_next_idler and time() > vstatus.time_of_next_idler:
 701                 vstatus.time_of_next_idler = time() + 30
 702                 choose_idler()
 703
 704         ###
 705
 706         vstatus.mk.update_display()
 707
 708         vstatus.change_state(STATE_GRANDFATHER_CLOCK)
 709         run_handler(event, params, v, vstatus)
 710         sleep(0.05)
 711
 712 def beep_on(when, before=0):
 713         start = int(when - before)
 714         end = int(when)
 715         now = int(time())
 716
 717         if now >= start and now <= end:
 718                 return 1
 719         return 0
 720
 721 def handle_idle_grandfather_tick(state, event, params, v, vstatus):
 722         ### check for interesting times
 723         now = localtime()
 724
 725         quarterhour = mktime([now[0],now[1],now[2],now[3],15,0,now[6],now[7],now[8]])
 726         halfhour = mktime([now[0],now[1],now[2],now[3],30,0,now[6],now[7],now[8]])
 727         threequarterhour = mktime([now[0],now[1],now[2],now[3],45,0,now[6],now[7],now[8]])
 728         fivetothehour = mktime([now[0],now[1],now[2],now[3],55,0,now[6],now[7],now[8]])
 729
 730         hourfromnow = localtime(time() + 3600)
 731
 732         #onthehour = mktime([now[0],now[1],now[2],now[3],03,0,now[6],now[7],now[8]])
 733         onthehour = mktime([hourfromnow[0],hourfromnow[1],hourfromnow[2],hourfromnow[3], \
 734                 0,0,hourfromnow[6],hourfromnow[7],hourfromnow[8]])
 735
 736         ## check for X seconds to the hour
 737         ## if case, update counter to 2
 738         if beep_on(onthehour,15) \
 739                 or beep_on(halfhour,0) \
 740                 or beep_on(quarterhour,0) \
 741                 or beep_on(threequarterhour,0) \
 742                 or beep_on(fivetothehour,0):
 743                 vstatus.change_state(STATE_GRANDFATHER_CLOCK,2)
 744                 run_handler(event, params, v, vstatus)
 745         else:
 746                 vstatus.change_state(STATE_IDLE)
 747
 748 def handle_grandfather_tick(state, event, params, v, vstatus):
 749         go_idle = 1
 750
 751         msg = []
 752         ### we live in interesting times
 753         now = localtime()
 754
 755         quarterhour = mktime([now[0],now[1],now[2],now[3],15,0,now[6],now[7],now[8]])
 756         halfhour = mktime([now[0],now[1],now[2],now[3],30,0,now[6],now[7],now[8]])
 757         threequarterhour = mktime([now[0],now[1],now[2],now[3],45,0,now[6],now[7],now[8]])
 758         fivetothehour = mktime([now[0],now[1],now[2],now[3],55,0,now[6],now[7],now[8]])
 759
 760         hourfromnow = localtime(time() + 3600)
 761
 762 #       onthehour = mktime([now[0],now[1],now[2],now[3],03,0,now[6],now[7],now[8]])
 763         onthehour = mktime([hourfromnow[0],hourfromnow[1],hourfromnow[2],hourfromnow[3], \
 764                 0,0,hourfromnow[6],hourfromnow[7],hourfromnow[8]])
 765
 766
 767         #print "when it fashionable to wear a onion on your hip"
 768
 769         if beep_on(onthehour,15):
 770                 go_idle = 0
 771                 next_hour=((hourfromnow[3] + 11) % 12) + 1
 772                 if onthehour - time() < next_hour and onthehour - time() > 0:
 773                         v.beep(0, False)
 774
 775                         t = int(time())
 776                         if (t % 2) == 0:
 777                                 msg.append(("DING!", False, None))
 778                         else:
 779                                 msg.append(("     DING!", False, None))
 780                 elif int(onthehour - time()) == 0:
 781                         v.beep(255, False)
 782                         msg.append(("   BONG!", False, None))
 783                         msg.append(("     IT'S "+ str(next_hour) + "O'CLOCK AND ALL IS WELL .....", False, TEXT_SPEED*4))
 784         elif beep_on(halfhour,0):
 785                 go_idle = 0
 786                 v.beep(0, False)
 787                 msg.append((" HALFHOUR ", False, 50))
 788         elif beep_on(quarterhour,0):
 789                 go_idle = 0
 790                 v.beep(0, False)
 791                 msg.append((" QTR HOUR ", False, 50))
 792         elif beep_on(threequarterhour,0):
 793                 go_idle = 0
 794                 v.beep(0, False)
 795                 msg.append((" 3 QTR HR ", False, 50))
 796         elif beep_on(fivetothehour,0):
 797                 go_idle = 0
 798                 v.beep(0, False)
 799                 msg.append(("Quick run to your lectures!  Hurry! Hurry!", False, TEXT_SPEED*4))
 800         else:
 801                 go_idle = 1
 802
 803         ## check for X seconds to the hour
 804
 805         if len(msg):
 806                 vstatus.mk.set_messages(msg)
 807                 sleep(1)
 808
 809         vstatus.mk.update_display()
 810         ## if no longer case, return to idle
 811
 812         ## change idler to be clock
 813         if go_idle and vstatus.mk.done():
 814                 vstatus.change_state(STATE_IDLE,1)
 815
 816 def handle_door_idle(state, event, params, v, vstatus):
 817         def twiddle(clock,v,wise = 2):
 818                 if (clock % 4 == 0):
 819                         v.display("-FEED  ME-")
 820                 elif (clock % 4 == 1+wise):
 821                         v.display("\\FEED  ME/")
 822                 elif (clock % 4 == 2):
 823                         v.display("-FEED  ME-")
 824                 elif (clock % 4 == 3-wise):
 825                         v.display("/FEED  ME\\")
 826
 827         # don't care right now.
 828         now = int(time())
 829
 830         if ((now % 60 % 2) == 0):
 831                 twiddle(now, v)
 832         else:
 833                 twiddle(now, v, wise=0)
 834
 835
 836 def handle_door_event(state, event, params, v, vstatus):
 837         if params == 0:  #door open
 838                 vstatus.change_state(STATE_DOOR_OPENING)
 839                 logging.warning("Entering open door mode")
 840                 v.display("-FEED  ME-")
 841                 #door_open_mode(v);
 842                 vstatus.cur_user = ''
 843                 vstatus.cur_pin = ''
 844         elif params == 1:  #door closed
 845                 vstatus.change_state(STATE_DOOR_CLOSING)
 846                 reset_idler(v, vstatus, 3)
 847
 848                 logging.warning('Leaving open door mode')
 849                 v.display("-YUM YUM!-")
 850
 851
 852 def handle_mifare_event(state, event, params, v, vstatus):
 853         global _last_card_id
 854         card_id = params
 855         # Translate card_id into uid.
 856         if card_id == None or card_id == _last_card_id:
 857                 return
 858
 859         _last_card_id = card_id
 860
 861         try:
 862                 vstatus.cur_user = get_uid(card_id)
 863                 logging.info('Mapped card id to uid %s'%vstatus.cur_user)
 864                 vstatus.username = get_uname(vstatus.cur_user)
 865                 if acct_is_disabled(vstatus.username):
 866                         vstatus.username = '-disabled-'
 867         except ValueError:
 868                 vstatus.username = None
 869         if vstatus.username == '-disabled-':
 870                 v.beep(40, False)
 871                 vstatus.mk.set_messages(
 872                         [(center('ACCT DISABLED'), False, 1.0),
 873                          (center('SORRY'), False, 0.5)])
 874                 vstatus.cur_user = ''
 875                 vstatus.cur_pin = ''
 876                 vstatus.username = None
 877
 878                 reset_idler(v, vstatus, 2)
 879                 return
 880         elif vstatus.username:
 881                 v.beep(0, False)
 882                 vstatus.cur_selection = ''
 883                 vstatus.change_state(STATE_GET_SELECTION)
 884                 scroll_options(vstatus.username, vstatus.mk, True)
 885                 return
 886         else:
 887                 v.beep(40, False)
 888                 vstatus.mk.set_messages(
 889                         [(center('BAD CARD'), False, 1.0),
 890                          (center('SORRY'), False, 0.5)])
 891                 vstatus.cur_user = ''
 892                 vstatus.cur_pin = ''
 893                 _last_card_id = -1
 894
 895                 reset_idler(v, vstatus, 2)
 896                 return
 897
 898 def handle_mifare_add_user_event(state, event, params, v, vstatus):
 899         global _last_card_id
 900         card_id = params
 901
 902         # Translate card_id into uid.
 903         if card_id == None or card_id == _last_card_id:
 904                 return
 905
 906         _last_card_id = card_id
 907
 908         try:
 909                 if get_uid(card_id) != None:
 910                         vstatus.mk.set_messages(
 911                                 [(center('ALREADY'), False, 0.5),
 912                                  (center('ENROLLED'), False, 0.5)])
 913
 914                         # scroll_options(vstatus.username, vstatus.mk)
 915                         return
 916         except ValueError:
 917                 pass
 918
 919         logging.info('Enrolling card %s to uid %s (%s)'%(card_id, vstatus.cur_user, vstatus.username))
 920         set_card_id(vstatus.cur_user, card_id)
 921         vstatus.mk.set_messages(
 922                 [(center('CARD'), False, 0.5),
 923                  (center('ENROLLED'), False, 0.5)])
 924
 925         # scroll_options(vstatus.username, vstatus.mk)
 926
 927 def return_to_idle(state,event,params,v,vstatus):
 928         reset_idler(v, vstatus)
 929
 930 def create_state_table(vstatus):
 931         vstatus.state_table[(STATE_IDLE,TICK,1)] = handle_idle_tick
 932         vstatus.state_table[(STATE_IDLE,KEY,1)] = handle_idle_key
 933         vstatus.state_table[(STATE_IDLE,DOOR,1)] = handle_door_event
 934         vstatus.state_table[(STATE_IDLE,MIFARE,1)] = handle_mifare_event
 935
 936         vstatus.state_table[(STATE_DOOR_OPENING,TICK,1)] = handle_door_idle
 937         vstatus.state_table[(STATE_DOOR_OPENING,DOOR,1)] = handle_door_event
 938         vstatus.state_table[(STATE_DOOR_OPENING,KEY,1)] = do_nothing
 939         vstatus.state_table[(STATE_DOOR_OPENING,MIFARE,1)] = do_nothing
 940
 941         vstatus.state_table[(STATE_DOOR_CLOSING,TICK,1)] = return_to_idle
 942         vstatus.state_table[(STATE_DOOR_CLOSING,DOOR,1)] = handle_door_event
 943         vstatus.state_table[(STATE_DOOR_CLOSING,KEY,1)] = do_nothing
 944         vstatus.state_table[(STATE_DOOR_CLOSING,MIFARE,1)] = do_nothing
 945
 946         vstatus.state_table[(STATE_GETTING_UID,TICK,1)] = handle_getting_uid_idle
 947         vstatus.state_table[(STATE_GETTING_UID,DOOR,1)] = handle_door_event
 948         vstatus.state_table[(STATE_GETTING_UID,KEY,1)] = handle_getting_uid_key
 949         vstatus.state_table[(STATE_GETTING_UID,MIFARE,1)] = handle_mifare_event
 950
 951         vstatus.state_table[(STATE_GETTING_PIN,TICK,1)] = handle_getting_pin_idle
 952         vstatus.state_table[(STATE_GETTING_PIN,DOOR,1)] = handle_door_event
 953         vstatus.state_table[(STATE_GETTING_PIN,KEY,1)] = handle_getting_pin_key
 954         vstatus.state_table[(STATE_GETTING_PIN,MIFARE,1)] = handle_mifare_event
 955
 956         vstatus.state_table[(STATE_GET_SELECTION,TICK,1)] = handle_get_selection_idle
 957         vstatus.state_table[(STATE_GET_SELECTION,DOOR,1)] = handle_door_event
 958         vstatus.state_table[(STATE_GET_SELECTION,KEY,1)] = handle_get_selection_key
 959         vstatus.state_table[(STATE_GET_SELECTION,MIFARE,1)] = handle_mifare_add_user_event
 960
 961         vstatus.state_table[(STATE_GRANDFATHER_CLOCK,TICK,1)] = handle_idle_grandfather_tick
 962         vstatus.state_table[(STATE_GRANDFATHER_CLOCK,TICK,2)] = handle_grandfather_tick
 963         vstatus.state_table[(STATE_GRANDFATHER_CLOCK,DOOR,1)] = handle_door_event
 964         vstatus.state_table[(STATE_GRANDFATHER_CLOCK,DOOR,2)] = handle_door_event
 965         vstatus.state_table[(STATE_GRANDFATHER_CLOCK,KEY,1)] = do_nothing
 966         vstatus.state_table[(STATE_GRANDFATHER_CLOCK,KEY,2)] = do_nothing
 967         vstatus.state_table[(STATE_GRANDFATHER_CLOCK,MIFARE,1)] = handle_mifare_event
 968
 969 def get_state_table_handler(vstatus, state, event, counter):
 970         return vstatus.state_table[(state,event,counter)]
 971
 972 def time_to_next_update(vstatus):
 973         idle_update = vstatus.time_of_next_idlestep - time()
 974         if not vstatus.mk.done() and vstatus.mk.next_update is not None:
 975                 mk_update = vstatus.mk.next_update - time()
 976                 if mk_update < idle_update:
 977                         idle_update = mk_update
 978         return idle_update
 979
 980 def run_forever(rfh, wfh, options, cf):
 981         v = VendingMachine(rfh, wfh, USE_MIFARE)
 982         vstatus = VendState(v)
 983         create_state_table(vstatus)
 984
 985         logging.debug('PING is ' + str(v.ping()))
 986
 987         if USE_DB: db = DispenseDatabase(v, cf.DBServer, cf.DBName, cf.DBUser, cf.DBPassword)
 988
 989         setup_idlers(v)
 990         reset_idler(v, vstatus)
 991
 992         # This main loop was hideous and the work of the devil.
 993         # This has now been fixed (mostly) - mtearle
 994         #
 995         #
 996         # notes for later surgery
 997         #   (event, counter, ' ')
 998         #        V
 999         #   d[      ] = (method)
1000         #
1001         # ( return state - not currently implemented )
1002
1003         while True:
1004                 if USE_DB:
1005                         try:
1006                                 db.handle_events()
1007                         except DispenseDatabaseException, e:
1008                                 logging.error('Database error: '+str(e))
1009
1010                 timeout = time_to_next_update(vstatus)
1011                 e = v.next_event(timeout)
1012                 (event, params) = e
1013
1014                 run_handler(event, params, v, vstatus)
1015
1016 #               logging.debug('Got event: ' + repr(e))
1017
1018
1019 def run_handler(event, params, v, vstatus):
1020         handler = get_state_table_handler(vstatus,vstatus.state,event,vstatus.counter)
1021         if handler:
1022                 handler(vstatus.state, event, params, v, vstatus)
1023
1024 def connect_to_vend(options, cf):
1025
1026         if options.use_lat:
1027                 logging.info('Connecting to vending machine using LAT')
1028                 latclient = LATClient(service = cf.ServiceName, password = cf.ServicePassword, server_name = cf.ServerName, connect_password = cf.ConnectPassword, priv_password = cf.PrivPassword)
1029                 rfh, wfh = latclient.get_fh()
1030         elif options.use_serial:
1031                 # Open vending machine via serial.
1032                 logging.info('Connecting to vending machine using serial')
1033                 serialclient = SerialClient(port = '/dev/ttyS1', baud = 9600)
1034                 rfh,wfh = serialclient.get_fh()
1035         else:
1036                 #(rfh, wfh) = popen2('../../virtualvend/vvend.py')
1037                 logging.info('Connecting to virtual vending machine on %s:%d'%(options.host,options.port))
1038                 import socket
1039                 sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM, 0)
1040                 sock.connect((options.host, options.port))
1041                 rfh = sock.makefile('r')
1042                 wfh = sock.makefile('w')
1043                 global USE_MIFARE
1044                 USE_MIFARE = 0
1045
1046         return rfh, wfh
1047
1048 def parse_args():
1049         from optparse import OptionParser
1050
1051         op = OptionParser(usage="%prog [OPTION]...")
1052         op.add_option('-f', '--config-file', default='/etc/dispense2/servers.conf', metavar='FILE', dest='config_file', help='use the specified config file instead of /etc/dispense/servers.conf')
1053         op.add_option('--serial', action='store_true', default=True, dest='use_serial', help='use the serial port')
1054         op.add_option('--lat', action='store_true', default=False, dest='use_lat', help='use LAT')
1055         op.add_option('--virtualvend', action='store_false', default=True, dest='use_serial', help='use the virtual vending server instead of LAT')
1056         op.add_option('-n', '--hostname', dest='host', default='localhost', help='the hostname to connect to for virtual vending machine mode (default: localhost)')
1057         op.add_option('-p', '--port', dest='port', default=5150, type='int', help='the port number to connect to (default: 5150)')
1058         op.add_option('-l', '--log-file', metavar='FILE', dest='log_file', default='', help='log output to the specified file')
1059         op.add_option('-s', '--syslog', dest='syslog', metavar='FACILITY', default=None, help='log output to given syslog facility')
1060         op.add_option('-d', '--daemon', dest='daemon', action='store_true', default=False, help='run as a daemon')
1061         op.add_option('-v', '--verbose', dest='verbose', action='store_true', default=False, help='spit out lots of debug output')
1062         op.add_option('-q', '--quiet', dest='quiet', action='store_true', default=False, help='only report errors')
1063         op.add_option('--pid-file', dest='pid_file', metavar='FILE', default='', help='store daemon\'s pid in the given file')
1064         options, args = op.parse_args()
1065
1066         if len(args) != 0:
1067                 op.error('extra command line arguments: ' + ' '.join(args))
1068
1069         return options
1070
1071 config_options = {
1072         'DBServer': ('Database', 'Server'),
1073         'DBName': ('Database', 'Name'),
1074         'DBUser': ('VendingMachine', 'DBUser'),
1075         'DBPassword': ('VendingMachine', 'DBPassword'),
1076
1077         'ServiceName': ('VendingMachine', 'ServiceName'),
1078         'ServicePassword': ('VendingMachine', 'Password'),
1079
1080         'ServerName': ('DecServer', 'Name'),
1081         'ConnectPassword': ('DecServer', 'ConnectPassword'),
1082         'PrivPassword': ('DecServer', 'PrivPassword'),
1083         }
1084
1085 class VendConfigFile:
1086         def __init__(self, config_file, options):
1087                 try:
1088                         cp = ConfigParser.ConfigParser()
1089                         cp.read(config_file)
1090
1091                         for option in options:
1092                                 section, name = options[option]
1093                                 value = cp.get(section, name)
1094                                 self.__dict__[option] = value
1095
1096                 except ConfigParser.Error, e:
1097                         raise SystemExit("Error reading config file "+config_file+": " + str(e))
1098
1099 def create_pid_file(name):
1100         try:
1101                 pid_file = file(name, 'w')
1102                 pid_file.write('%d\n'%os.getpid())
1103                 pid_file.close()
1104         except IOError, e:
1105                 logging.warning('unable to write to pid file '+name+': '+str(e))
1106
1107 def set_stuff_up():
1108         def do_nothing(signum, stack):
1109                 signal.signal(signum, do_nothing)
1110         def stop_server(signum, stack): raise KeyboardInterrupt
1111         signal.signal(signal.SIGHUP, do_nothing)
1112         signal.signal(signal.SIGTERM, stop_server)
1113         signal.signal(signal.SIGINT, stop_server)
1114
1115         options = parse_args()
1116         config_opts = VendConfigFile(options.config_file, config_options)
1117         if options.daemon: become_daemon()
1118         set_up_logging(options)
1119         if options.pid_file != '': create_pid_file(options.pid_file)
1120
1121         return options, config_opts
1122
1123 def clean_up_nicely(options, config_opts):
1124         if options.pid_file != '':
1125                 try:
1126                         os.unlink(options.pid_file)
1127                         logging.debug('Removed pid file '+options.pid_file)
1128                 except OSError: pass  # if we can't delete it, meh
1129
1130 def set_up_logging(options):
1131         logger = logging.getLogger()
1132
1133         if not options.daemon:
1134                 stderr_logger = logging.StreamHandler(sys.stderr)
1135                 stderr_logger.setFormatter(logging.Formatter('%(levelname)s: %(message)s'))
1136                 logger.addHandler(stderr_logger)
1137
1138         if options.log_file != '':
1139                 try:
1140                         file_logger = logging.FileHandler(options.log_file)
1141                         file_logger.setFormatter(logging.Formatter('%(asctime)s %(levelname)s: %(message)s'))
1142                         logger.addHandler(file_logger)
1143                 except IOError, e:
1144                         logger.warning('unable to write to log file '+options.log_file+': '+str(e))
1145
1146         if options.syslog != None:
1147                 sys_logger = logging.handlers.SysLogHandler('/dev/log', options.syslog)
1148                 sys_logger.setFormatter(logging.Formatter('vendserver[%d]'%(os.getpid()) + ' %(levelname)s: %(message)s'))
1149                 logger.addHandler(sys_logger)
1150
1151         if options.quiet:
1152                 logger.setLevel(logging.WARNING)
1153         elif options.verbose:
1154                 logger.setLevel(logging.DEBUG)
1155         else:
1156                 logger.setLevel(logging.INFO)
1157
1158 def become_daemon():
1159         dev_null = file('/dev/null')
1160         fd = dev_null.fileno()
1161         os.dup2(fd, 0)
1162         os.dup2(fd, 1)
1163         os.dup2(fd, 2)
1164         try:
1165                 if os.fork() != 0:
1166                         sys.exit(0)
1167                 os.setsid()
1168         except OSError, e:
1169                 raise SystemExit('failed to fork: '+str(e))
1170
1171 def do_vend_server(options, config_opts):
1172         while True:
1173                 try:
1174                         rfh, wfh = connect_to_vend(options, config_opts)
1175                 except (SerialClientException, socket.error), e:
1176                         (exc_type, exc_value, exc_traceback) = sys.exc_info()
1177                         del exc_traceback
1178                         logging.error("Connection error: "+str(exc_type)+" "+str(e))
1179                         logging.info("Trying again in 5 seconds.")
1180                         sleep(5)
1181                         continue
1182
1183 #               run_forever(rfh, wfh, options, config_opts)
1184
1185                 try:
1186                         run_forever(rfh, wfh, options, config_opts)
1187                 except VendingException:
1188                         logging.error("Connection died, trying again...")
1189                         logging.info("Trying again in 5 seconds.")
1190                         sleep(5)
1191
1192
1193 def main(argv=None):
1194         options, config_opts = set_stuff_up()
1195         while True:
1196                 try:
1197                         logging.warning('Starting Vend Server')
1198                         do_vend_server(options, config_opts)
1199                         logging.error('Vend Server finished unexpectedly, restarting')
1200                 except KeyboardInterrupt:
1201                         logging.info("Killed by signal, cleaning up")
1202                         clean_up_nicely(options, config_opts)
1203                         logging.warning("Vend Server stopped")
1204                         break
1205                 except SystemExit:
1206                         break
1207                 except:
1208                         (exc_type, exc_value, exc_traceback) = sys.exc_info()
1209                         tb = format_tb(exc_traceback, 20)
1210                         del exc_traceback
1211
1212                         logging.critical("Uh-oh, unhandled " + str(exc_type) + " exception")
1213                         logging.critical("Message: " + str(exc_value))
1214                         logging.critical("Traceback:")
1215                         for event in tb:
1216                                 for line in event.split('\n'):
1217                                         logging.critical('    '+line)
1218                         logging.critical("This message should be considered a bug in the Vend Server.")
1219                         logging.critical("Please report this to someone who can fix it.")
1220                         sleep(10)
1221                         logging.warning("Trying again anyway (might not help, but hey...)")
1222
1223 if __name__ == '__main__':
1224         sys.exit(main())