Forum OpenACS Development: apm_package_instantiate_and_mount triggers QD bug?
Posted by
Jonathan Marsden
on 08/27/01 04:07 AM
RH 7.1, PG 7.1.3, AOLserver 3.3.1+ad13, current OpenACS4 from CVS.
I can install and play with OpenACS4 on this system now. However, in trying to get the auto-install.tcl non-interactive installer working I have found an interesting bug which I'm not sure how to track down further.
Essentially, calling the TCL function apm_package_instantiate_and_mount always generates a non-parseable db_0or1row query. The parser error message refers to "$1", which sounds like it might be a QD thing??
I turned on debug in nsd.tcl and generated masses of logfile output which still didn't show me the SQL from the failing query, beyond a plpgsql query which calls other plpgsql functions...
Here's the short testing.tcl file which reliably causes this.
ns_write "HTTP/1.0 200 OK Content-Type: text/html <title>test</title><body> <H1>Mounting packages</H1><p><pre><blockquote>" ns_log Notice "JM_IS_TESTING2: Testing2 started." ns_write " <p>Will try to instantiate and mount pkg key: page</p> <p>" ns_log Notice "JM_IS_TESTING2: Will try to instantiate and mount pkg key: page" apm_package_instantiate_and_mount -callback apm_ns_write_callback page ns_write "</blockquote></pre><p>Done.</p>" ns_log Notice "JM_IS_TESTING2: Test completed." db_release_unused_handles ns_write "<p><strong>Testing Complete.</strong></p></body></html>"
It has wrapped in a couple of places where it isn't supposed to... grrrr. And here is the AOLserver log file output, also abominably wrapped:
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Notice: JM_IS_TESTING2:
Testing2 started.
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Notice: JM_IS_TESTING2:
Will try to instantiate and mount pkg key: page
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = calling
namespace =
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER =
proc_name is -apm_package_instantiate_and_mount-
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = tcl
file is packages/acs-tcl/tcl/apm-install-procs.tcl
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = TEMP -
QD: proc_name is apm_package_instantiate_and_mount
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = TEMP -
QD: local_name is package_instantiate_and_mount
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER =
generated fullname of
dbqd.acs-tcl.tcl.apm-install-procs.apm_package_instantiate_and_mount.package_instantiate_and_mount
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = query
dbqd.acs-tcl.tcl.apm-install-procs.apm_package_instantiate_and_mount.package_instantiate_and_mount
from /var/lib/aolserver/servers/openacs4/packages/acs-tcl/tcl/apm-inst
all-procs-postgresql.xql
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER =
PLPGSQL: using anonymous function
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = PRE-QD:
the SQL is
declare
main_site_id site_nodes.node_id%TYPE;
instance_id apm_packages.package_id%TYPE;
node_id site_nodes.node_id%TYPE;
begin
main_site_id := site_node.node_id('/');
instance_id := apm_package.new(
package_key => :package_key,
context_id => main_site_id
);
node_id := site_node.new(
parent_id => main_site_id,
name => :package_key,
directory_p => 't',
pattern_p => 't',
object_id => instance_id
);
end;
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = query
dbqd.acs-tcl.tcl.apm-install-procs.apm_package_instantiate_and_mount.package_instantiate_and_mount
from /var/lib/aolserver/servers/openacs4/packages/acs-tcl/tcl/apm-inst
all-procs-postgresql.xql
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER =
POST-QD: the SQL is
declare
main_site_id site_nodes.node_id%TYPE;
instance_id apm_packages.package_id%TYPE;
node_id site_nodes.node_id%TYPE;
begin
main_site_id := site_node__node_id('/',null);
instance_id := apm_package__new(
null,
null,
:package_key,
'apm_package',
now(),
null,
null,
main_site_id
);
node_id := site_node__new(
null
main_site_id,
:package_key,
instance_id,
't',
't',
null,
null
);
return null;
end;
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = calling
namespace =
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER =
proc_name is -db_nextval-
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = tcl
file is packages/acs-tcl/tcl/00-database-procs-postgresql.tcl
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = TEMP -
QD: proc_name is db_nextval
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = TEMP -
QD: local_name is nextval
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER =
generated fullname of
dbqd.acs-tcl.tcl.00-database-procs-postgresql.db_nextval.nextval
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = PRE-QD:
the SQL is select anon_func_seq.nextval for
dbqd.acs-tcl.tcl.00-database-procs-postgresql.db_nextval.nextval
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER = NO
FULLQUERY FOR
dbqd.acs-tcl.tcl.00-database-procs-postgresql.db_nextval.nextval -->
using default SQL
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER =
POST-QD: the SQL is select anon_func_seq.nextval
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: PgBindCmd: sql =
select anon_func_seq.nextval
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Debug: QD_LOGGER =
PLPGSQL: converted:
declare
main_site_id site_nodes.node_id%TYPE;
instance_id apm_packages.package_id%TYPE;
node_id site_nodes.node_id%TYPE;
begin
main_site_id := site_node__node_id('/',null);
instance_id := apm_package__new(
null,
null,
:package_key,
'apm_package',
now(),
null,
null,
main_site_id
);
node_id := site_node__new(
null
main_site_id,
:package_key,
instance_id,
't',
't',
null,
null
);
return null;
end;
to: select __exec_13_package_instantiate_and_mount ()
NOTICE: identifier "__exec_13_package_instantiate_and_mount" will be
truncated to "__exec_13_package_instantiate_a"
NOTICE: identifier "__exec_13_package_instantiate_and_mount" will be
truncated to "__exec_13_package_instantiate_a"
NOTICE: Adding missing FROM-clause entry for table "acs_object_id_seq"
NOTICE: identifier "acs_object__initialize_attributes" will be
truncated to "acs_object__initialize_attribut"
NOTICE: identifier "apm_package__initialize_parameters" will be
truncated to "apm_package__initialize_paramet"
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Error: Ns_PgExec: result
status: 7 message: ERROR: parser: parse error at or near "$1"
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Error: dbinit:
error(localhost::openacs4,ERROR: parser: parse error at or near "$1"
): 'select __exec_13_package_instantiate_and_mount ()'
NOTICE: identifier "__exec_13_package_instantiate_and_mount" will be
truncated to "__exec_13_package_instantiate_a"
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Notice: Page not
mounted. Error:
Database operation "0or1row" failed
(exception NSDB, "Query was not a statement returning
rows.")
[27/Aug/2001:02:40:55][30817.4101][-conn0-] Notice: JM_IS_TESTING2:
Test completed.
192.168.1.192 - - [27/Aug/2001:02:40:55 +0100] "GET
/acs-admin/testing2.tcl HTTP/1.0" 200 0 "" "Lynx/2.8.4dev.16
libwww-FM/2.14 SSL-MM/1.4.1 OpenSSL/0.9.6"
