View Single Post
Unread 01-28-13, 05:48 PM   #4
spiel2001
nUI's Author
 
spiel2001's Avatar
AddOn Author - Click to view addons
Join Date: Jun 2008
Posts: 7,724
By way of follow-up, since I've gotten a few e-mails since posting this thread, I wanted to explain a little about what's going on in the new '/console taintlog 11'

In a nutshell, *EVERY* time an addon sets a variable, that variable is tainted. It does not matter if it is a top level global, such as "UIDROPDOWNMENU_MENU_LEVEL" or a member of a table such as 'MyAddonSavedVars.someValue' or, for that matter, even a function name. Anything and everything an addon does outside of the secure environment is by definition tainted.

Generally speaking, that's not an issue. The only time it becomes an issue is when the Blizzard code, or a secure code snippet, tries to read from a variable that's been tainted, or execute a tainted function, while in a secure execution path. As soon as that happens, the execution path becomes tainted and you can no longer execute secure calls... i.e. buttons don't work, spell casts fail, etc. Anything that is "secure" in Blizzard's point of view, will no longer work once the execution path becomes tainted.

So, as long as the execution path is not tainted, everything is sunshine and lollipops. However, Once the execution path is tainted, no secure functions or abilities will work until the path is terminated. So, then, the question becomes what tainted the execution path when, where and how.

In the simplest case, when this happens, you get a message to the effect of "Interface action failed because of an AddOn" and unless you have a bug tracker like BugSack or Swatter installed, and you have logging of warnings enabled, that's all you know about it. By default, the taint log is turned off (/console taintlog 0), so you have no information there, either. So, you turn the taint log on using the command '/console taintlog 1' and reload the user interface, reproduce the error and log out. When you do that, you'll find a file called 'taint.log' in the [ World of Warcraft > Logs ] folder. It will contain minimal information about the event, but often that is enough.

However, you do have the option of using the command '/console taintlog 2' to increase the logging level, as well. In this mode, the taint.log will contain more information, basically telling you who tainted the thing that caused the execution path to be tainted. But, even then, that's often not enough to track down subtle taint problems. Speaking for myself, I've had some taint issues in my code that have been there for years because I couldn't figure them out using the taint log as it existed up until the 5.2 patch.

Enter '/console taintlog 11' (turn it up to 11 dude!) and the modifications that were made to how taint is reported in 5.2

The key to understanding this expanded taint.log mode is to understand that it logs *every* taint event *every time* it happens. It does not just log the first time a variable is tainted, but every time. Nor does it log the first time the execution path is tainted, but every time. Quite literally, every single taint event is written to the log along with the offender and, quite often, a stack trace.

A quick caveat -- at present, the taint.log does not fully expand the variables names. I'm hoping that will change. It does not differentiate between a top level global variable name like 'UIDROPDOWNMENU_MENU_LEVEL' and 'MyAddonVars.UIDROPDOWNMENU_MENU_LEVEL' -- it will report *both* as 'Global variable UIDROPDOWNMENU_MENU_LEVEL tainted by MyAddon' -- that makes it a little problematic when you get a message like 'Global variable id has been tainted by MyAddon' -- okay... unitFrame.id, actionButton.id, mything.id or what? This probably will not get fixed in 5.2, but let's cross our fingers. It is being looked at.

If you've got a busy addon, lots of OnUpdate and OnEvent stuff going on, it can easily produce a couple hundred meg of taint.log in minutes or even seconds. Trying to read this file manually will make your head explode. Regex is your friend. I mucked about with grepWin for a while and it did okay... I just hated that I couldn't chain (pipe) rules, nor should I only show lines that didn't match the rule. I'm a linux guy, so I just copied the output to my Linux VM and had at it with grep. To be sure, the pathway to enlightenment passes through pattern searching.

For myself, nirvana was turning off every other addon I use, including bug catchers like BugSack and Swatter, and running with nothing but my own addon enabled. Logged in, used the '/console taintlog 11' command and logged back out. Then logged back in, immediately reproduced the taint error and immediately logged back out. Ten seconds logged in, maybe 15. My taint.log was close to 250 meg. I then used grep (regular expression search) to make a list of all of the times the execution path was tainted and all of the variables that caused it to be tainted. From there I worked backwards to build a list of every place in the code where I tainted that variable. It was fast and easy... far more so than it has even been for me in the nearly 5 years that nUI has been around. It took me about five minutes to fix a taint error that I haven't been able to find for months. In under an hour, I had fixed every taint error I had, even some I never knew were there.

It takes a bit to get your head around the scale of data in the new taint log, but I promise you once you do, you'll see how quickly it can help you resolve taint problems... even really hard to find ones.
__________________

What people don't get is that I am, ultimately, an artist at heart.
My brush has two colors, 1 and 0, and my canvas is made of silicon.



Official nUI Web Site: http://www.nUIaddon.com
Official nUI Support Forum: http://forums.nUIaddon.com
My day job: http://www.presidio.com/

Last edited by spiel2001 : 01-28-13 at 09:03 PM.
spiel2001 is offline   Reply With Quote