try except question - serious foo bar question, and pulling my hair out :-)

[Laszlo Nagy]

Given this class below:

import Queue
import threading
from sorb.util.dumpexc import dumpexc
import waitablemixin


PREFETCH_SIZE = 10

class Feeder(threading.Thread,waitablemixin.WaitableMixin):
    def __init__(self,connection_manager):
        self.cm = connection_manager
        self.expired_asins = Queue.Queue()
        self.logger = self.cm.loggerfactory.get_logger("feeder")
        threading.Thread.__init__(self)

    def run(self):
        try:
            try:
                d = self.cm.create_dispatcher()
                try:
                    od_producer = d.locate('od_producer')
                    while not self.cm.stop_requested.isSet():
                        try:
                            items = od_producer.getsomeasins()
                            if items:
                                self.logger.info("Got %d items to 
process",len(items))
                                for item in items:
                                    self.expired_asins.put(item)
                                if self.expired_asins.qsize()>PREFETCH_SIZE:
                                    while 
(self.expired_asins.qsize()>PREFETCH_SIZE) and \
                                        not self.cm.stop_requested.isSet():
                                        self.logger.info(
                                            "%s (>%s) items in the 
queue, waiting...",
                                            self.expired_asins.qsize(),
                                            PREFETCH_SIZE
                                        )
                                        self.waitsome(1)
                            else:
                                self.logger.info("No more items to 
process, will wait 5 minutes.")
                                self.waitsome(5*60)
                        except Exception,e:
                            self.logger.error("Could not get asins: 
%s",dumpexc(e) )
                            self.logger.error("Will retry in 10 seconds.")
                            self.waitsome(10)
                finally:
                    d.close()
            except Exception,e:
                self.cm.stop_requested.set()
                self.logger.error(dumpexc(e))
        finally:
            self.logger.error("Feeder stopped. stop_requested = 
%s",str(self.cm.stop_requested.isSet()))
        
            
How in the hell can I get the following log output:

2009-02-24 11:42:14,696 INFO .feeder Got 5 items to process
2009-02-24 11:42:14,732 INFO .feeder Got 5 items to process
2009-02-24 11:42:14,733 INFO .feeder 15 (>10) items in the queue, waiting...
2009-02-24 11:42:15,740 INFO .feeder 15 (>10) items in the queue, waiting...
2009-02-24 11:42:16,965 ERROR .feeder Feeder stopped. stop_requested = False

It seems impossible to me. The while loop should only exit if 
stop_requested becomes set, OR if an exception is raised. However, all 
exceptions are cought and logged. But there are no exceptions logged. 
And stop_requested is NOT SET. (see the last line in the log).

What is happening here?