Python bug? Named parameters in recursive calls sometimes confuses python?

[Magnus Lyck?]

Something really strange is happening to me (sometimes).
I'm using Python 2.3.2 on NT 4.0 as well as win32all-157,
adodbapi and db_row.

During a recursive call to a method, it seems Python messes
up its variable bindings once in a while. Suddenly, one of
several local variables gets rebound to the object it was bound
to one step up in the recursion.

The relevant part of the code looks like this with print statements
that show the problem. This problem only seems to occur for certain
input to my program.

Note that I print the same variables and object IDs three times, and
suddenly, a variable has changed its binding (without any reassignment)
to the value it had one level up in the recursion.

def recursiveCopy(self, table, column, old_val, new_val):
# Fetch row from source database
print "1. Column %s (%i) Table %s (%i)" % (column, id(column),
table, id(table))

sql = "SELECT * FROM %(schema)s.%(table)s WHERE %(column)s = ?"
rows = self.src_fetch(sql, params=(old_val,), table=table,
column=column)
# I use "sql % kwargs" in a method called by src_fetch

print "2. Column %s (%i) Table %s (%i)" % (column, id(column),
table, id(table))

for row in rows:
# Replace foreign key with value for target DB

print "3. Column %s (%i) Table %s (%i)" % (column, id(column),
table, id(table))

row[column] = new_val # <= This is where it crashes.
# What's interesting is the print above before the crash.
# row is a db_row.IMetaRow instance instance.

# We need primary key values for recursive find
# Only bother for table with a single p.k.
parent_p_key_cols = self.getPK(table)
if len(parent_p_key_cols) == 1:
parent_p_key_col = parent_p_key_cols[0]
oldId = row[parent_p_key_col]
newId = self.insertIntoTarget(table, row)
for child_table, column in self.getDepTables(table,
parent_p_key_col):
self.recursiveCopy(child_table, column, oldId, newId)

The output looks like this:

1. Column G06_PERS_INTRID (9282024) Table TGANST (9282768)
2. Column G06_PERS_INTRID (9282024) Table TGANST (9282768)
3. Column G06_PERS_INTRID (9282024) Table TGANST (9282768)
1. Column G60_ANSTID (9283512) Table TGANSTOV (10002536)
2. Column G60_ANSTID (9283512) Table TGANSTOV (10002536)
1. Column G08_ANSTID (10003232) Table TGANSTU (10002920)
2. Column G08_ANSTID (10003232) Table TGANSTU (10002920)
3. Column G08_ANSTID (10003232) Table TGANSTU (10002920)
1. Column G15_ANSTID (10002704) Table TGBELOPP (10003184)
2. Column G15_ANSTID (10002704) Table TGBELOPP (10003184)
1. Column G45_ANSTID (10002752) Table TGLED (9282672)
2. Column G45_ANSTID (10002752) Table TGLED (9282672)
1. Column G46_ANSTID (10002728) Table TGLON (10002512)
2. Column G46_ANSTID (10002728) Table TGLON (10002512)
3. Column G46_ANSTID (10002728) Table TGANST (9282768) <= N.B.
Table magically morphed.
Traceback (most recent call last):
File "D:\NYPONVerktyg\Test\masterexport\get_person.py", line 364, in ?
main()
File "D:\NYPONVerktyg\Test\masterexport\get_person.py", line 336, in main
move()
File "D:\NYPONVerktyg\Test\masterexport\get_person.py", line 254, in move
transfer.start(pnr)
File "D:\NYPONVerktyg\Test\masterexport\get_person.py", line 181, in start
self.recursiveCopy(table, column, old_pnr, new_pnr)
File "D:\NYPONVerktyg\Test\masterexport\get_person.py", line 164, in recursiveCopy
self.recursiveCopy(child_table, column, oldId, newId)
File "D:\NYPONVerktyg\Test\masterexport\get_person.py", line 154, in recursiveCopy
row[column] = new_val
File "D:/NYPONVerktyg/Test/masterexport\db_row.py", line 526, in __setitem__
self.fields.__setitem__(key,value)
File "D:/NYPONVerktyg/Test/masterexport\db_row.py", line 370, in __setitem__
setattr(self, i, value)
File "D:/NYPONVerktyg/Test/masterexport\db_row.py", line 456, in __setattr__
super(IFieldsBase, self).__setattr__(key.lower(),value)
AttributeError: 'irow_fields' object has no attribute 'g46_anstid'

Note that the 'table' variable (which is bound to a unicode object) changed
value from TGLON to TGANST and id from 10002512 to 9282768. I.e. we seem to
have jumped up one step in the stack. But the 'column' variable stayed
unchanged, so we haven't popped the stack frame either!

Actually, it's even more weird. The table TGLON is empty, so self.src_fetch
ought to have returned an empty 'rows' variable, in which case we wouldn't
go into the loop, and would never see 'print "3. ...' Even though "print 2"
says TGLON, it seems TGANST is what got into the call of self.src_fetch,
and since DB2 didn't complain, it seems column actually have the value
G06_PERS_INTRID at that time (???). (Alternatively, we also reverted to
a previous rows-object?)

If I change the variable names to avoid "column=column" etc like this...

def recursiveCopy(self, table_, column_, old_val, new_val):
# Fetch row from source database
print "1. Column %s (%i) Table %s (%i)" % (column_, id(column_),
table_, id(table_))

sql = "SELECT * FROM %(schema)s.%(table)s WHERE %(column)s = ?"
rows = self.src_fetch(sql, params=(old_val,), table=table_,
column=column_)

....the problem seems to go away. (But it only occurred for some input
anyway. Maybe it just moved...)

 

[Michael Hudson]

Something really strange is happening to me (sometimes).
I'm using Python 2.3.2 on NT 4.0 as well as win32all-157,
adodbapi and db_row.

During a recursive call to a method, it seems Python messes
up its variable bindings once in a while. Suddenly, one of
several local variables gets rebound to the object it was bound
to one step up in the recursion.

I don't seem to have th brain cells to really understand your code
this morning (and obviously can't run it myself), but at first blush
it seems vastly more likely that you're confused than Python.

I've never heard of a bug like this before.

The relevant part of the code looks like this with print statements
that show the problem. This problem only seems to occur for certain
input to my program.

Note that I print the same variables and object IDs three times, and
suddenly, a variable has changed its binding (without any reassignment)
to the value it had one level up in the recursion.
[snip]
The output looks like this:

1. Column G06_PERS_INTRID (9282024) Table TGANST (9282768)
2. Column G06_PERS_INTRID (9282024) Table TGANST (9282768)
3. Column G06_PERS_INTRID (9282024) Table TGANST (9282768)
1. Column G60_ANSTID (9283512) Table TGANSTOV (10002536)
2. Column G60_ANSTID (9283512) Table TGANSTOV (10002536)
1. Column G08_ANSTID (10003232) Table TGANSTU (10002920)
2. Column G08_ANSTID (10003232) Table TGANSTU (10002920)
3. Column G08_ANSTID (10003232) Table TGANSTU (10002920)
1. Column G15_ANSTID (10002704) Table TGBELOPP (10003184)
2. Column G15_ANSTID (10002704) Table TGBELOPP (10003184)
1. Column G45_ANSTID (10002752) Table TGLED (9282672)
2. Column G45_ANSTID (10002752) Table TGLED (9282672)
1. Column G46_ANSTID (10002728) Table TGLON (10002512)
2. Column G46_ANSTID (10002728) Table TGLON (10002512)
3. Column G46_ANSTID (10002728) Table TGANST (9282768) <= N.B.
Table magically morphed.

Isn't it possible that the code has just returned twice?

Unless you can produce an example that can be run somewhere other than
your setup, it's going to be pretty hard for someone else to debug
this!

Cheers,
mwh

 

[Duncan Booth]

(e-mail address removed) (Magnus Lyck?) wrote in

def recursiveCopy(self, table, column, old_val, new_val):
# Fetch row from source database
print "1. Column %s (%i) Table %s (%i)" % (column, id(column),
table, id(table))

sql = "SELECT * FROM %(schema)s.%(table)s WHERE %(column)s =
?" rows = self.src_fetch(sql, params=(old_val,), table=table,
column=column)
# I use "sql % kwargs" in a method called by src_fetch

print "2. Column %s (%i) Table %s (%i)" % (column, id(column),
table, id(table))

for row in rows:
# Replace foreign key with value for target DB

print "3. Column %s (%i) Table %s (%i)" % (column,
id(column),
table,
id(table))

row[column] = new_val # <= This is where it crashes.
# What's interesting is the print above before the crash.
# row is a db_row.IMetaRow instance instance.

# We need primary key values for recursive find
# Only bother for table with a single p.k.
parent_p_key_cols = self.getPK(table)
if len(parent_p_key_cols) == 1:
parent_p_key_col = parent_p_key_cols[0]
oldId = row[parent_p_key_col]
newId = self.insertIntoTarget(table, row)
for child_table, column in self.getDepTables(table,

parent_p_key_col):
self.recursiveCopy(child_table, column, oldId,
newId)

I note that you reassign the 'column' variable in that last for loop. I
think your last line of output is simply the second time around the 'for
row in rows' in the outermost call. Perhaps if you used a different
variable name for that second variable called 'column' you wouldn't get so
confused.

 

[Magnus Lyck?]

(e-mail address removed) (Magnus Lyck?) writes:

Isn't it possible that the code has just returned twice?

I don't know... But in that case, we have accidentally
retained the value of "column" which we had one step
down in the recursion, instead of reverting to the object
which is bound to the local variable at this level. Still
a Python bug!

2. Column G46_ANSTID (10002728) Table TGLON (10002512)
3. Column G46_ANSTID (10002728) Table TGANST (9282768) <= N.B.

As you can see below, the variables passed in to recursiveCopy
as column and table are reassigned together, in:
"for child_table, column in self.getDepTables(..."
getDepTables returns data it gets directly from SQL queries,
so it should never return a value which is passed in, and
either way, in my case it's table that changes while column
stays the same. (Are unicode objects interned?) Anyway,
there is no way that the database could return the
combination G46_ANSTID / TGANST.

G46_ANSTID belongs with TGLON, and TGLON is dependant on
TGANST. *IF* we simply returned from the recursive call to
the previous level, column should be G06_PERS_INTRID (9282024),
just as it was before, when table was TGANST (9282768).

Column and table are reassigned together. If one of them changes
while the other doesn't, there is something wrong!

It happens here:

def recursiveCopy(self, table, column, old_val, new_val):
# Fetch row from source database
print "1. Column %s (%i) Table %s (%i)" % (column, id(column),
table, id(table))

sql = "SELECT * FROM %(schema)s.%(table)s WHERE %(column)s = ?"
rows = self.src_fetch(sql, params=(old_val,), table=table,
column=column)
# I use "sql % kwargs" in a method called by src_fetch

print "2. Column %s (%i) Table %s (%i)" % (column, id(column),
table, id(table))

for row in rows:
# Replace foreign key with value for target DB

print "3. Column %s (%i) Table %s (%i)" % (column, id(column),
table, id(table))

row[column] = new_val # <= This is where it crashes.
# What's interesting is the print above before the crash.
# row is a db_row.IMetaRow instance instance.

# We need primary key values for recursive find
# Only bother for table with a single p.k.
parent_p_key_cols = self.getPK(table)
if len(parent_p_key_cols) == 1:
parent_p_key_col = parent_p_key_cols[0]
oldId = row[parent_p_key_col]
newId = self.insertIntoTarget(table, row)
for child_table, column in self.getDepTables(table,
parent_p_key_col):
self.recursiveCopy(child_table, column, oldId, newId)

Unless you can produce an example that can be run somewhere other than
your setup, it's going to be pretty hard for someone else to debug
this!

I realize that... I was hoping that someone else
had seen something similar. Unfortunately I'm not even
at liberty to publish the code I write now... The bug
only appears for particular data (but it occurred twice,
on different computers) and the program assumes a certain
database etc. I doubt that I'll be able to reproduce it
in a small package, and it wouldn't surprise me if it's
an NT 4 specific bug. (Not a lot of users on that old
platform I guess...)

Assuming I have understood what the problem is, the
relevant parts of the code looks something like this:

class X:
def fetch(self, sql, params, **kwargs):
...
cursor.execute(sql % kwargs, params)
return a list of db_row objects from cursor.fetchall()

def recCopy(self, table, column, ...):
sql = '...'
rows = self.fetch(sql, params=(...), table=table, column=column)
for row in rows:
...
for child_table, foreign_key_col in getDependantTables(table):
self.recCopy(child_table, foreign_key_col , ...)

In the middle of one call of recCopy, a local variable seems to be
rebound. The suspects are:
* Recursion?
* Named parameters, especially "x=x"?
* Unicode objects?
* Something in win32all/adodbapi?
* Something in db_row? Metaclasses? (It's the pure Python version 0.8)
* Windows NT 4.0 SP 6?
* Just me?

Can anyone suggest a way to go forward here? I have found ways
to avoid the problem, but there seems to be a sinister Python
bug lurking here and I would like to help bring it to the surface.

Can I see what recursion depth I'm currently at? I have never
used the more arcane powers of Python introspection such as the
inspect module etc.

 

[John J. Lee]

Something really strange is happening to me (sometimes).
I'm using Python 2.3.2 on NT 4.0 as well as win32all-157,
adodbapi and db_row.

During a recursive call to a method, it seems Python messes
up its variable bindings once in a while. Suddenly, one of
several local variables gets rebound to the object it was bound
to one step up in the recursion.

[...]

Try sticking in an extra parameter to the recursive function,
recursion_level=0, print and incrementing it at the start of the
function, and make sure every recursive call passes that optional
argument.


John

 

[Magnus Lyck?]

I note that you reassign the 'column' variable in that last for loop. I
think your last line of output is simply the second time around the 'for
row in rows' in the outermost call. Perhaps if you used a different
variable name for that second variable called 'column' you wouldn't get so
confused.

Silly me! Thank's Duncan. This really confused me a lot.
Initially, I was sure it was one of these normal "I'm
sure it's obvious once I spot it" problems, but somehow,
I managed not to spot it for a very long time.

This feels very reassuring. I was starting to wonder if
there was something problematic with Python 2.3.2 on NT...
Lucky it was just me being blind!