Wednesday, October 14, 2009

Getting more from tracebacks

Now that I've spammed my readers with a useless "test post via email" note, I will try to post something of value.

I have always been fond of saying "tracebacks are our friends". In my mind, tracebacks are not to be feared... the bigger the traceback the better because that means that I have more information available to me to debug the problem.

A common debugging technique is to put a call to the !traceback!() procedure in any method from which you want to determine how the call stack arrived at that method. Placing a !traceback!() call in your code won't raise a condition or stop the code flow. It will simply give you a dump of the call stack at that point.

To demonstrate how this works, I have put a !traceback!() call in the Web Map Connector's ve_tile.draw_on() method. The traceback looks as you would expect...

---- traceback: renderer (heavy_thread 3611775) ----
time=14/10/2009 17:00:21
sw!version=4.1.0 (swaf)
os_text_encoding=cp1252
!snapshot_traceback?!=False

!traceback!()
a ve_tile(detached) .draw_on(a sw:canvas)
sw:simple_vector:[1-11].fast_keys_and_elements()
sw:keyed_set(1).valid_indices(False)
sw:keyed_set(1).fast_elements()
sw:keyed_set(1).elements()
transient_rwo_collection(road_tile).fast_elements()
sw:simple_vector:[1-11].fast_keys_and_elements()
sw:hash_table(1).valid_indices(False)
sw:hash_table(1).fast_elements()
ve_dataset(ve_dataset).scan_elements(a bounding_box, sw:rope:[1-1], sw:hash_table(0))
a sw:uds_geometry_set(ve_dataset,0,0).scan_elements(a bounding_box, sw:rope:[1-1], sw:hash_table(0))
a sw:uds_geometry_set(ve_dataset,0,0).elements()
a sw:uds_geometry_set(ve_dataset,0,0).draw_on(a sw:canvas, unset)
sw:rope:[1-4].elements()
a sw:composite_geometry_set.draw_on(a sw:canvas, unset)
a sw:canvas.paint(True, a sw:composite_geometry_set, unset)
a sw:canvas.draw(a sw:composite_geometry_set)
map_view(map(Electricity),region).super(map_view).original!int!do_render(unset)
map_view(map(Electricity),region).int!do_render(unset)
renderer(map_view(map(Electricity),region), unset)
light_thread_launcher_proc_990928()


There is a global variable !snapshot_traceback?! that you set to _true to give you a bit more information.

MagikSF> !snapshot_traceback?! << _true
$


Now the traceback looks like...

---- traceback: renderer (heavy_thread 3563153) ----
time=14/10/2009 17:01:44
sw!version=4.1.0 (swaf)
os_text_encoding=cp1252
!snapshot_traceback?!=True

[1] !traceback!()
[2] a ve_tile(detached) .draw_on(a sw:canvas)
[3] sw:simple_vector:[1-11].fast_keys_and_elements()
[4] sw:keyed_set(1).valid_indices(False)
[5] sw:keyed_set(1).fast_elements()
[6] sw:keyed_set(1).elements()
[7] transient_rwo_collection(road_tile).fast_elements()
[8] sw:simple_vector:[1-11].fast_keys_and_elements()
[9] sw:hash_table(1).valid_indices(False)
[10] sw:hash_table(1).fast_elements()
[11] ve_dataset(ve_dataset).scan_elements(a bounding_box, sw:rope:[1-1], sw:hash_table(0))
[12] a sw:uds_geometry_set(ve_dataset,0,0).scan_elements(a bounding_box, sw:rope:[1-1], sw:hash_table(0))
[13] a sw:uds_geometry_set(ve_dataset,0,0).elements()
[14] a sw:uds_geometry_set(ve_dataset,0,0).draw_on(a sw:canvas, unset)
[15] sw:rope:[1-4].elements()
[16] a sw:composite_geometry_set.draw_on(a sw:canvas, unset)
[17] a sw:canvas.paint(True, a sw:composite_geometry_set, unset)
[18] a sw:canvas.draw(a sw:composite_geometry_set)
[19] map_view(map(Electricity),region).super(map_view).original!int!do_render(unset)
[20] map_view(map(Electricity),region).int!do_render(unset)
[21] renderer(map_view(map(Electricity),region), unset)
[22] light_thread_launcher_proc_990928()



... as you can see, each traceback line is numbered. This is kind of handy to have. The real benefits of !snapshot_traceback?! are described in the public comments for this global variable.

What I wanted to show you is a modification I made to the !traceback!() procedure that gives you even more helpful information whilst !snapshot_traceback?! is _true.

Here is my hack of the !traceback!() procedure.

#% text_encoding = iso8859_1
_package sw
$
_global !traceback! <<
_proc@traceback(_optional stream, max_depth, full?)
## Display traceback of calls in the current thread on
## STREAM. If max_depth is given, at most that number of
## stack frames will be displayed.
##
## If !traceback_show_args?! is true, then the arguments will
## be shown along with the method name.
##
## Tracebacks normally exclude stack frames after a
## condition.raise(). Setting FULL? to _true will force the
## full traceback to be shown. I.e including tracebacks of any
## condition handlers.

_thisthread.traceback(stream, !traceback_show_args?!,max_depth, full?)

_global !snapshot_traceback?!

_if !snapshot_traceback?! _is _true
_then

_global !ts!
_local sfile , meth

write("These numbered source files correspond to the methods in the numbered lines in the traceback above.")

_for i,v _over !ts!.fast_keys_and_elements()
_loop
meth << v.receiver.method(v.message)

_if meth _is _unset
_then
show(write_string("[",i,"]"))
_continue
_endif

sfile << meth.source_file
_dynamic !show_string_length! << sfile.size
show(write_string("[",i,"]"),sfile)
_endloop
_endif
_endproc
$



You can see that it calls the standard _thisthread.traceback() method, but after that it takes a list of all the methods/procedures that were reported in the traceback and shows their source files as well...


---- traceback: renderer (heavy_thread 3514507) ----
time=14/10/2009 17:05:41
sw!version=4.1.0 (swaf)
os_text_encoding=cp1252
!snapshot_traceback?!=True

[1] traceback()
[2] a ve_tile(detached) .draw_on(a sw:canvas)
[3] sw:simple_vector:[1-11].fast_keys_and_elements()
[4] sw:keyed_set(1).valid_indices(False)
[5] sw:keyed_set(1).fast_elements()
[6] sw:keyed_set(1).elements()
[7] transient_rwo_collection(road_tile).fast_elements()
[8] sw:simple_vector:[1-11].fast_keys_and_elements()
[9] sw:hash_table(1).valid_indices(False)
[10] sw:hash_table(1).fast_elements()
[11] ve_dataset(ve_dataset).scan_elements(a bounding_box, sw:rope:[1-1], sw:hash_table(0))
[12] a sw:uds_geometry_set(ve_dataset,0,0).scan_elements(a bounding_box, sw:rope:[1-1], sw:hash_table(0))
[13] a sw:uds_geometry_set(ve_dataset,0,0).elements()
[14] a sw:uds_geometry_set(ve_dataset,0,0).draw_on(a sw:canvas, unset)
[15] sw:rope:[1-4].elements()
[16] a sw:composite_geometry_set.draw_on(a sw:canvas, unset)
[17] a sw:canvas.paint(True, a sw:composite_geometry_set, unset)
[18] a sw:canvas.draw(a sw:composite_geometry_set)
[19] map_view(map(Electricity),region).super(map_view).original!int!do_render(unset)
[20] map_view(map(Electricity),region).int!do_render(unset)
[21] renderer(map_view(map(Electricity),region), unset)
[22] light_thread_launcher_proc_990928()
These numbered source files correspond to the methods in the numbered lines in the traceback above.
"[1]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/general/procedure.magik"
"[2]" "C:\DOCUME~1\Alfred\LOCALS~1\Temp\TAlfred9412q0"
"[3]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/mixins/ro_indexed_collection_mixin.magik"
"[4]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/new_sys_changes.magik"
"[5]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/convert2_sf/hashing/hash_values_helper.magik"
"[6]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/new_sys_changes.magik"
"[7]" "c:/swdev/build/410/410_PB_WINDOWS/unshipped/source/sys_core/ds_src/dd/dd_collection_mixin.magik"
"[8]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/mixins/ro_indexed_collection_mixin.magik"
"[9]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/new_sys_changes.magik"
"[10]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/convert2_sf/hashing/hash_values_helper.magik"
"[11]" "C:/ifactor/products/workspace/Virtual_Earth_Connector/trunk/modules/ve_som/source\ve_dataset.magik"
"[12]" "C:/Smallworld41/product/modules/sw_core/geometry_vector/source/uds_geometry_set.magik"
"[13]" "C:/Smallworld41/product/modules/sw_core/geometry_vector/source/uds_geometry_set.magik"
"[14]" "C:/Smallworld41/product/modules/sw_core/geometry_vector/source/geometry_set_mixin.magik"
"[15]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/mixins/rope_mixin.magik"
"[16]" "C:/Smallworld41/product/modules/sw_core/geometry_vector/source/composite_geometry_set.magik"
"[17]" "c:/swdev/build/410/410_PB_WINDOWS/unshipped/source/sys_core/mgr_src/user/drawing_surface_mixin.magik"
"[18]" "c:/swdev/build/410/410_PB_WINDOWS/unshipped/source/sys_core/mgr_src/user/drawing_surface_mixin.magik"
"[19]" "C:\ifactor\products\workspace\Virtual_Earth_Connector\trunk\source\patches_z_proposed\p1000001_1_if_vec_map_plugin.magik"
"[20]" "C:\ifactor\products\workspace\Virtual_Earth_Connector\trunk\source\patches_z_proposed\p1000001_1_if_vec_map_plugin.magik"
"[21]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/general/procedure.magik"
"[22]" "/swdev/streams/leo/release/unshipped/source/sys_core/sys_src/general/procedure.magik"


This can be very helpful when you are trying to debug why certain code works in one of your environments but not the other. It can be very helpful to the GE Help Desk team because sending this enhanced traceback will tell them how your call stack is different than the one they are testing in. It will show which methods were changed in patches and in custom code.
Test post via email.

Monday, October 5, 2009

Preventing ACE posting

It has long been known that posting up ACE and/or CASE alternatives may have unintended consequences when the parent/child alternatives have records that are in conflict. If you ever want to prevent all users from posting an ACE alternative, you can use this code I wrote to do that.

This code snippet has been written in a patch format. You can read more about how to create your own patches here.
The define_method_synonym() approach is described here. Note that because the core method database_view.post() source code is not shipped with the product, we need to use the define_method_synonym() approach to wrap our own custom functionality around it without modifying the core restricted functionality.


#% text_encoding = iso8859_1
_package sw
$
sw!patch_software( "ds_src", 1 )
$
# use define_method_synonym() to wrap some of our behavior
# around the core method without redefining the core behavior.
_if database_view.method(:original!post|()|) _is _unset
_then
database_view.define_method_synonym(:original!post|()|,:post|()|)
_endif
$
_pragma(classify_level=restricted, usage={redefinable})
_method database_view.post(_gather args)
## Post changes in this alternative to the parent,
## performing an implicit commit() if any updates are
## outstanding.
##
## Returns _true if there were changes to post, _false
## otherwise.
##
## If the data dictionary has been modified, then the modified
## version must have been allocated a datamodel version first.
##
## External databases are checked to ensure that if they are
## updated, that they are prepared to commit (i.e. they are
## running). An error is raised if one is not prepared to
## commit.
##
## THIS REDEFINED VERSION OF THE METHOD HAS BEEN MODIFIED TO
## DISALLOW POSTING ACE ALTERNATIVES.

_if _self.name.canonical _is :ace
_then
condition.raise(:cannot_post_ace_database)
_endif
_return _self.original!post(_scatter args)
_endmethod
$
_pragma(classify_level=restricted, usage={redefinable})
## raised by database_view.post() when database_view is named
## :ace.
condition.define_condition(:cannot_post_ace_database,:user_error,{})
$
read_message_patch(:condition,_unset,:en_us)
$
:cannot_post_ace_database Posting ACE alternatives is not safe and has been disabled.
$

sw!declare_patch(1000000001,"1cst","Prevents posting ACE alternative.")
$