Just for posterity, having (I think) solved this problem, I'd like to explain what I did. > Notice that in both sets of anaconda logs the "spoke is ready: ..." and > "setting <object> status to: ..." come in batches, right next to each > other. They are nowhere near the threads that send the messages, most > are happening after their associated threads are actually done. > > This could be a logging artifact, maybe they just aren't being logged > until later for some reason. But since the reporters are seeing actual > problems I am suspicious that something is holding up hubQ and it is > processing them all at about the same time. What's going on here is that the logging messages are generated at the end of some branch of the case in _update_spokes. This was only getting run once per second (I bumped it to 100ms in my patch), which necessarily means the messages are going to get logged a long ways off from where the messages get enqueued. Long story short, we can't actually trust our logging of this kind of stuff. We could, perhaps, do the logging when the messages are enqueued instead of when they are processed. That'd make our logging make more sense, but would mean the log would be less coupled to the actual state of the UI. > Anyone have any ideas for debugging this? Our hunch was that the problem was the storage execute thread was running multiple times. Thus I worked backwards from it - figure out exactly where an execute method can be run. There's three places in hubs/__init__.py where that happens. Given that our logging is unreliable, I just added print statements that showed what spoke was executing and what method in __init__.py was calling execute. Sure enough, a couple were getting called multiple times - from _createBox and from _update_spokes. This is because certain spokes have a changed method that always returns True. I couldn't change that without breaking other things (git log on spokes/storage.py for explanation), so I just introduced another attribute that prevents execute from running if the spoke hasn't actually been visited since execute last ran. - Chris _______________________________________________ Anaconda-devel-list mailing list Anaconda-devel-list@xxxxxxxxxx https://www.redhat.com/mailman/listinfo/anaconda-devel-list
