"type" being redefined

Kimberly_Horne · September 19, 2012, 7:43am

We’re seeing some stack traces in 915 that would indicate that the global “type” is being redefined. In particular, we’re seeing messages such as this:

2012-09-19 10:33:28.443 Corona Simulator[75140:707] Runtime error
?:0: attempt to call global ‘type’ (a number value)
stack traceback:
[C]: in function ‘type’
?: in function ‘?’
?: in function ‘_initTween’
?: in function <?:1100>
?: in function <?:229>

We’ve done a sweep of our code and have confirmed that we’re not doing this ourselves. I’m not sure how this comes about, but it’s a catastrophic bug - all of our functions that rely on type checking are exploding.

This bug doesn’t exhibit itself initially but does appear after some amount of play time. Unfortunately, we cannot provide any steps to reproduce. [import]uid: 117383 topic_id: 31142 reply_id: 331142[/import]

Kimberly_Horne · September 19, 2012, 7:57am

We were really hoping to get a build out early for iPhone 5, with our thinking being that Apple might be keen at fast tracking approval (and potentially featuring) apps that have specifically gone out of their way to support the capabilities of the new device. Given the state of the Corona iOS6 support we’re hesitant because we don’t want to sacrifice stability to achieve that attention. [import]uid: 117383 topic_id: 31142 reply_id: 124550[/import]

Ntero · September 19, 2012, 8:23am

In the first line of main.lua do this:

local typeMask = type  
local function checkWrite(table, key, value)  
 if key == "type" then  
 print("Gotcha!", debug.traceback())  
 end  
 rawset(\_G, key, value)  
end  
  
local function hideGet(table, key)  
 if key == "type" then  
 return typeMask  
 else  
 return rawget(\_G, key)  
 end  
end  
  
\_G.type = nil  
setmetatable(\_G, { \_\_newindex = checkWrite, \_\_index = hideGet})

This is some hacky sorta code that will allow you to catch who and when type is modified.
The moment any code (yours or otherwise) tries to touch the type function it’ll print out a callstack.

Edit: To help understand what this code is doing is that it is removing the type function from the global namespace and replacing all accesses and indexes with a function that mimics the original behaviour. All old accesses will act the same with the exception that now you have a place where you can intercept where your particular element is assigned. It has to be nil-ed out, because __newindex is only called when you are assigning to a previously unused indexd and not when overwriting. Metatables allow you to do a lot of really interesting interception and redirection tricks with tables.

Edit: Another use for this logger is that if you remove the check for “type” in checkWrite, you can also have it track ALL globals added, which in our case are usually accidentally forgetting local, and so it allows you to track where you can clean up code that is polluting the global table. [import]uid: 134101 topic_id: 31142 reply_id: 124553[/import]

Kimberly_Horne · September 19, 2012, 8:26am

Aha! Thank you, I will try this. Hopefully we can narrow this down fast. [import]uid: 117383 topic_id: 31142 reply_id: 124558[/import]

Kimberly_Horne · September 19, 2012, 11:04am

The plot gets… weirder. Since applying your test above we haven’t been seeing the bug (or the printed warning) but we have been seeing other issues that can have similar catastrophic effects. Their stacks are even stranger, however. ie:

bad argument #-1 to ‘?’ (647Proxy expected, got table)
stack traceback:
[C]: ?
[C]: ?
?: in function <?:1100>
?: in function <?:229>

647Proxy? Buh?

at first I thought the metatable hack above might have been interfering with another metatable already set on _G but no such luck - there doesn’t appear to be one. Very, very strange. [import]uid: 117383 topic_id: 31142 reply_id: 124592[/import]

Naomi · September 19, 2012, 11:19am

@Kimberly Horne, I don’t mean to highjack the thread (and unfortunately, I don’t know how to help trouble shoot your problem…), but I noted @Ntero’s comment about how his code can track ALL globals added, which sounds like a great tool.

So… @Ntero, will you describe how I may use your code? I’m not sure how I may view all globals added to _G table.

Naomi
[import]uid: 67217 topic_id: 31142 reply_id: 124593[/import]

Ntero · September 19, 2012, 12:37pm

Very strange indeed.
Proxy generally refers to Corona native objects(Most Corona objects have an entry called _proxy that corresponds to the native-side part of the object), as well Index #-1 refers to whatever was on top of the Lua stack when using the native Lua bridge (communicating between Lua and C), rather than a specific index of a function call. Not sure what the number represents, looking at the initial error could be some sort of type info, but that’s a wild guess.

What’s interesting though with the new log is that the first two entries of the Callstacks have the exact same Line numbers as the initial type error, meaning it’s possible they are closely related, and the first error was masking the second error, although without filenames, we can’t really be sure of it.

If it is the native engine code, it’s possible they could be using rawset on _G.type, which would mean that it cannot be tracked :(. It would also mean that they wouldn’t overwrite the initial type function, but could possibly be getting the intial type function instead of their new value.

I think at this point you will need a Corona Rep on here to help, as there is no way either one of us is going to effectively figure out what 647proxy was supposed to be. Sorry I couldn’t get you a definitive answer so far.

@Naomi
Here is a simpler form I currently use (stripped slightly of dependencies)

local function globalWatch(g, key, value)  
 print("GlobalWatch", tostring(key) .. "has been added to \_G\n" .. debug.traceback())  
 rawset(g, key, value)  
end  
setmetatable(\_G, { \_\_index = globalWatch })

As mentioned above, it won’t detect overwriting of _G variables, but it will print a log each time a new key is created. [import]uid: 134101 topic_id: 31142 reply_id: 124608[/import]

Kimberly_Horne · September 19, 2012, 1:32pm

Thanks so much for your insight Ntero - I wasn’t hopeful for a solution here but your help in tracking this down has been most appreciated.

Also, the other reason your trick might not be catching the problem is that I have it backwards - some block of code defined a local variable named “type” and it’s just a scope collision. [import]uid: 117383 topic_id: 31142 reply_id: 124611[/import]

Kimberly_Horne · September 19, 2012, 7:57am

We were really hoping to get a build out early for iPhone 5, with our thinking being that Apple might be keen at fast tracking approval (and potentially featuring) apps that have specifically gone out of their way to support the capabilities of the new device. Given the state of the Corona iOS6 support we’re hesitant because we don’t want to sacrifice stability to achieve that attention. [import]uid: 117383 topic_id: 31142 reply_id: 124550[/import]

Ntero · September 19, 2012, 8:23am

In the first line of main.lua do this:

local typeMask = type  
local function checkWrite(table, key, value)  
 if key == "type" then  
 print("Gotcha!", debug.traceback())  
 end  
 rawset(\_G, key, value)  
end  
  
local function hideGet(table, key)  
 if key == "type" then  
 return typeMask  
 else  
 return rawget(\_G, key)  
 end  
end  
  
\_G.type = nil  
setmetatable(\_G, { \_\_newindex = checkWrite, \_\_index = hideGet})

This is some hacky sorta code that will allow you to catch who and when type is modified.
The moment any code (yours or otherwise) tries to touch the type function it’ll print out a callstack.

Edit: To help understand what this code is doing is that it is removing the type function from the global namespace and replacing all accesses and indexes with a function that mimics the original behaviour. All old accesses will act the same with the exception that now you have a place where you can intercept where your particular element is assigned. It has to be nil-ed out, because __newindex is only called when you are assigning to a previously unused indexd and not when overwriting. Metatables allow you to do a lot of really interesting interception and redirection tricks with tables.

Edit: Another use for this logger is that if you remove the check for “type” in checkWrite, you can also have it track ALL globals added, which in our case are usually accidentally forgetting local, and so it allows you to track where you can clean up code that is polluting the global table. [import]uid: 134101 topic_id: 31142 reply_id: 124553[/import]

Kimberly_Horne · September 19, 2012, 8:26am

Aha! Thank you, I will try this. Hopefully we can narrow this down fast. [import]uid: 117383 topic_id: 31142 reply_id: 124558[/import]

Kimberly_Horne · September 19, 2012, 11:04am

The plot gets… weirder. Since applying your test above we haven’t been seeing the bug (or the printed warning) but we have been seeing other issues that can have similar catastrophic effects. Their stacks are even stranger, however. ie:

bad argument #-1 to ‘?’ (647Proxy expected, got table)
stack traceback:
[C]: ?
[C]: ?
?: in function <?:1100>
?: in function <?:229>

647Proxy? Buh?

at first I thought the metatable hack above might have been interfering with another metatable already set on _G but no such luck - there doesn’t appear to be one. Very, very strange. [import]uid: 117383 topic_id: 31142 reply_id: 124592[/import]

Naomi · September 19, 2012, 11:19am

@Kimberly Horne, I don’t mean to highjack the thread (and unfortunately, I don’t know how to help trouble shoot your problem…), but I noted @Ntero’s comment about how his code can track ALL globals added, which sounds like a great tool.

So… @Ntero, will you describe how I may use your code? I’m not sure how I may view all globals added to _G table.

Naomi
[import]uid: 67217 topic_id: 31142 reply_id: 124593[/import]

Ntero · September 19, 2012, 12:37pm

Very strange indeed.
Proxy generally refers to Corona native objects(Most Corona objects have an entry called _proxy that corresponds to the native-side part of the object), as well Index #-1 refers to whatever was on top of the Lua stack when using the native Lua bridge (communicating between Lua and C), rather than a specific index of a function call. Not sure what the number represents, looking at the initial error could be some sort of type info, but that’s a wild guess.

What’s interesting though with the new log is that the first two entries of the Callstacks have the exact same Line numbers as the initial type error, meaning it’s possible they are closely related, and the first error was masking the second error, although without filenames, we can’t really be sure of it.

If it is the native engine code, it’s possible they could be using rawset on _G.type, which would mean that it cannot be tracked :(. It would also mean that they wouldn’t overwrite the initial type function, but could possibly be getting the intial type function instead of their new value.

I think at this point you will need a Corona Rep on here to help, as there is no way either one of us is going to effectively figure out what 647proxy was supposed to be. Sorry I couldn’t get you a definitive answer so far.

@Naomi
Here is a simpler form I currently use (stripped slightly of dependencies)

local function globalWatch(g, key, value)  
 print("GlobalWatch", tostring(key) .. "has been added to \_G\n" .. debug.traceback())  
 rawset(g, key, value)  
end  
setmetatable(\_G, { \_\_index = globalWatch })

As mentioned above, it won’t detect overwriting of _G variables, but it will print a log each time a new key is created. [import]uid: 134101 topic_id: 31142 reply_id: 124608[/import]

Kimberly_Horne · September 19, 2012, 1:32pm

Thanks so much for your insight Ntero - I wasn’t hopeful for a solution here but your help in tracking this down has been most appreciated.

Also, the other reason your trick might not be catching the problem is that I have it backwards - some block of code defined a local variable named “type” and it’s just a scope collision. [import]uid: 117383 topic_id: 31142 reply_id: 124611[/import]

Naomi · October 3, 2012, 2:30pm

@Ntero, thank you so much. It’s really good to use it. When I run my project with your code, I notice a third party module adds variables to _G table. It’s interesting and illuminating.

Thanks again.

Naomi

EDIT: I found this globalWatch super useful, so I went ahead and shared it here: http://developer.coronalabs.com/forum/2011/12/16/handy-code-snippets#comment-126283 [import]uid: 67217 topic_id: 31142 reply_id: 124627[/import]

Naomi · October 3, 2012, 2:30pm

@Ntero, thank you so much. It’s really good to use it. When I run my project with your code, I notice a third party module adds variables to _G table. It’s interesting and illuminating.

Thanks again.

Naomi

EDIT: I found this globalWatch super useful, so I went ahead and shared it here: http://developer.coronalabs.com/forum/2011/12/16/handy-code-snippets#comment-126283 [import]uid: 67217 topic_id: 31142 reply_id: 124627[/import]