Forum OpenACS Development: How to track values of SQL calls in NaviServer?

Hi!

I've got a problem with nasty SQL triggers and need to track the actual data that OpenACS has written into the database. However, NaviServer (all versions to my knowledge) does not show values in the error.log. Instead, it shows the colon variables.

This is an example what I can see with NaviServer:

SELECT im_timesheet_task__new (
:rest_oid, 'im_timesheet_task', now(), :rest_user_id, '127.0.0.1', null,
:project_nr,
:project_name,
:parent_id,
:material_id,
:cost_center_id,
:uom_id,
:project_type_id,
:project_status_id,
:note
)

Fortunately ]po[ still runs - more or less - on AOLserver 4.5.1, so I can get the output that I need:

SELECT im_timesheet_task__new (
'49235', 'im_timesheet_task', now(), '624', '127.0.0.1', null,
'task_49235',
'New Task',
'49224',
'12812',
NULL,
'320',
'100',
'76',
NULL
);

So how can I get this type of debugging output from NaviServer?

The NaviServer output style effectively blocks our entire "post mortem debugging" process, where I could just ask a customer to send me the error.log in order to reproduce what happened in some strange situations.

Cheers,
Frank

Collapse
Posted by Gustaf Neumann on
Not sure, where the problem is.
  • make sure to turn sql-debugging level on
    ns_logctl severity "Debug(sql)" on
    
  • make sure, the logminduration is small enough (NaviServer allows to log only entries a threshold)
    foreach pool [ns_db pools] {ns_db logminduration $pool 0}
    
If these commands are e.g. entered via ds/shell, the output will show up immediately in the error log, containing all substituted variables, no server restart required. This intensive loggin can be as well the same way turned off.

One can also colorize the output (see e.g. the sample config file openacs-config.tcl as provided from the NaviServer repository.

Is this, what you are after, or is there some other problem?

-g

[13/Aug/2017:11:59:39][29767.7f56cf12b700][-conn:openacs.org:59:583655-] Debug(sql): pool pool1 duration 0.002378 secs: '
            select message_id,
                   0 as n_attachments,
                   t.subject,
                   t.content,
                   t.format,
                   person__name(t.user_id) as user_name,
                   to_char(t.posting_date, 'YYYY-MM-DD HH24:MI:SS') as posting_date_ansi,
                   tree_level(t.tree_sortkey) as tree_level,
                   t.state,
                   t.user_id,
                   t.parent_id,
                   t.open_p,
                   t.max_child_sortkey,
                   u.screen_name
            from   forums_messages_approved t, users u
            where  t.forum_id = '14013'
            and    u.user_id = t.user_id
            and    t.tree_sortkey between tree_left('10000000000000000000110100001100') and tree_right('10000000000000000000110100001100')
            order  by t.posting_date, tree_sortkey
.xql query:
            select message_id,
                   0 as n_attachments,
                   t.subject,
                   t.content,
                   t.format,
                   person__name(t.user_id) as user_name,
                   to_char(t.posting_date, 'YYYY-MM-DD HH24:MI:SS') as posting_date_ansi,
                   tree_level(t.tree_sortkey) as tree_level,
                   t.state,
                   t.user_id,
                   t.parent_id,
                   t.open_p,
                   t.max_child_sortkey,
                   u.screen_name
            from   $table_name t, users u
            where  t.forum_id = :forum_id
            and    u.user_id = t.user_id
            and    t.tree_sortkey between tree_left(:tree_sortkey) and tree_right(:tree_sortkey)
            order  by $order_by
Collapse
Posted by Frank Bergmann on
Thanks a lot, I'll try this!

Frank