[python-win32] unexpected behavior for threaded Windows Service

[Jim Vickroy]

For those interested, attached is an alternate approach that **does**
exhibit the desired behavior.

This alternate approach registers a Windows Service Control Handler that
responds to a "stop" request rather than periodically checking for a stop
event.

I'm still curious to know why win32event.WaitForSingleObject(...) appears to
pause both (producer and consumer) threads rather than just the consumer
thread.

-- jv

-----Original Message-----
From: python-win32-bounces at python.org
[mailto:python-win32-bounces at python.org]On Behalf Of Jim Vickroy
Sent: Tuesday, September 21, 2004 9:42 AM
To: python-win32
Subject: [python-win32] unexpected behavior for threaded Windows Service


Attached is a "short" script that demonstrates an unexpected behavior of a
threaded, producer/consumer, Windows Service.

My expectation was that the producer would be queuing events every 2
(producer_pause) seconds while the consumer would be processing queued
events every 10 (consumer_pause) seconds.  However, the log, generated by
this Service, indicates the producer is queuing events at the same frequency
as the consumer is processing them.

Could someone help me to understand why the producer is not operating
independently of the consumer?


Thanks,

-- jv


P.S.

My system:
	Python 2.3.3
	pywin build 202
	Windows XP
-------------- next part --------------
'''
A MSW  Service with a producer and a consumer thread connected by a queue.

NOTES
   o This version
      + behaves as expected (i.e., producer and consumer threads behave independently of each others
         pause interval).
      + uses servicemanager.RegisterServiceCtrlHandler(...) to designate a handler of all MSW
         Service-related events rather than the win32event.WaitForSingleObject method of polling
         for a stop request.

AUTHOR
   jim.vickroy at noaa.gov
'''


import win32serviceutil, win32service
import Queue
from   thread  import start_new_thread
from   logging import getLogger, shutdown, Logger, FileHandler, Formatter, CRITICAL, ERROR, WARNING, INFO, DEBUG, NOTSET
from   time    import ctime, sleep, time




class Tester(win32serviceutil.ServiceFramework):

   _svc_name_         = 'Threaded.Services.Tester.version.2'
   _svc_display_name_ = _svc_name_.replace('.', ' ')
   _svc_deps_         = ['EventLog'] # optional -- names of services to be started before this one

   consumer_pause = 10. # seconds
   producer_pause =  2. # seconds


   def __init__(self, args):

      win32serviceutil.ServiceFramework.__init__(self, args)

      # create/configure a logger to record service activities ...
      self.log  = getLogger(self._svc_display_name_)
      filename  = '%s.log' % self._svc_display_name_
      recorder  = FileHandler(filename)
      formatter = Formatter('%(asctime)s, %(levelname)-8s, %(message)s')
      recorder.setLevel(DEBUG)
      recorder.setFormatter(formatter)
      self.log.addHandler(recorder)
      self.log.setLevel(DEBUG)

      # remaining infrastructure attributes ...
      self.events        = Queue.Queue() # events to be processed
      self.stop_received = False


   def SvcStop(self):

      self.ReportServiceStatus(win32service.SERVICE_STOP_PENDING) # send an acknowledgement to the SCM


   def SvcDoRun(self):

      start_new_thread(self.producer, ()) # no parameters to pass to the procedure

      import servicemanager # available only at runtime
      servicemanager.LogInfoMsg('%s started' % self._svc_display_name_) # record event in Microsoft Windows Application Events Log

      servicemanager.RegisterServiceCtrlHandler(self._svc_name_, self.service_events_handler)

      while not self.stop_received:
         while not self.events.empty():
            event = self.events.get()
            self.log.info('consumed "%s"' % event)
         for i in range(10):
            if self.stop_received: break
            sleep(self.consumer_pause/10)


   def producer(self):

      while not self.stop_received:
         event = ctime(time())
         try:
            self.events.put(event)
         except Exception, details:
            self.log.exception('events queuing failure')
         else:
            self.log.info('queued   "%s"' % event)
         for i in range(10):
            if self.stop_received: break
            sleep(self.producer_pause/10)


   def service_events_handler(self, operation):
      '''
      a MSW Control Handler Function for use with:
            servicemanager.RegisterServiceCtrlHandler(self._svc_name_, callback)
         as the *callback* parameter
      '''

      waitHint      = 5000
      win32ExitCode = 0

      if operation == win32service.SERVICE_CONTROL_PAUSE:
         # Do whatever it takes to pause here.
         state = win32service.SERVICE_PAUSED

      elif operation == win32service.SERVICE_CONTROL_CONTINUE:
         # Do whatever it takes to continue here.
         state = win32service.SERVICE_RUNNING

      elif operation == win32service.SERVICE_CONTROL_STOP:
         # perform all shutdown tasks
         import servicemanager # available only at runtime
         servicemanager.LogInfoMsg('%s stopped' % self._svc_display_name_) # record event in Microsoft Windows Application Events Log
         state    = win32service.SERVICE_STOPPED
         waitHint = 0
         self.ReportServiceStatus(state, waitHint, win32ExitCode)
         self.log.info('SHUTDOWN request received')
         shutdown()
         self.stop_received = True
         return

      elif operation == win32service.SERVICE_CONTROL_INTERROGATE:
         pass

      else:
         pass #> 'Unrecognized opcode %d\n' % operation

      self.ReportServiceStatus(state, waitHint, win32ExitCode)

      return




if __name__=='__main__':
   from win32serviceutil import HandleCommandLine
   HandleCommandLine(Tester)