Forum OpenACS Q&A: Error during oacs repository access locks up oacs 5.4.3

I have a fresh install of oacs 5.4.3 (aolserver 4.5.1, postgres 8.2.13, tcl 8.5.7 on a Solaris 11 kernel) which locked up while accessing the oacs repository to install new packages. After the error, I was unable to access any page on the site until I restarted the server. This happened a few times. The error occurs when there's a delay in accessing the oacs repository. Here's the error in the log:

[18/Jun/2009:00:13:11][1975.7][-default:3-] Error: Ns_PgExec: result status: 7 message: could not receive data from server: Error 0

[18/Jun/2009:00:13:11][1975.7][-default:3-] Error: Ns_PgExec: result status: 7 message: could not receive data from server: Error 0

[18/Jun/2009:00:13:11][1975.7][-default:3-] Error: Tcl exception:
Database operation "0or1row" failed
(exception ERROR, "could not receive data from server: Error 0
")

while executing
"ns_pg_bind 0or1row nsdb0 {
select nextval('acs_object_id_seq') as nextval
where (select relkind
..."
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec 0or1row $db $full_statement_name $sql"
("uplevel" body line 2)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec 0or1row $db $full_statement_name $sql]
}"
(procedure "db_0or1row" line 50)
invoked from within
"db_0or1row -dbn $dbn nextval_sequence "
select nextval('${sequence}') as nextval
where (select relkind
..."
(procedure "db_nextval" line 15)
invoked from within
"db_nextval acs_object_id_seq"
(procedure "rp_report_error" line 13)
invoked from within
"rp_report_error"
(procedure "rp_handler" line 139)
invoked from within
"rp_handler"

Has anyone encountered this or have any thoughts?

Thanks,
Prem Thomas

1. Here's the error returned by the browser:

Server Error
The requested URL cannot be accessed due to a system error on this server.

2. More from the log during the same error. It seems to set off a cascade:

[19/Jun/2009:00:32:14][1424.5][-default:2-] Error: Ns_PgExec: result status: 7 message: could not receive data from server: Error 0

[19/Jun/2009:00:32:14][1424.5][-default:2-] Error: Tcl exception:
Database operation "0or1row" failed
(exception ERROR, "could not receive data from server: Error 0
")

while executing
"ns_pg_bind 0or1row nsdb0 {
select nextval('acs_object_id_seq') as nextval
where (select relkind
..."
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec 0or1row $db $full_statement_name $sql"
("uplevel" body line 2)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec 0or1row $db $full_statement_name $sql]
}"
(procedure "db_0or1row" line 50)
invoked from within
"db_0or1row -dbn $dbn nextval_sequence "
select nextval('${sequence}') as nextval
where (select relkind
..."
(procedure "db_nextval" line 15)
invoked from within
"db_nextval acs_object_id_seq"
(procedure "rp_report_error" line 13)
invoked from within
"rp_report_error"
(procedure "rp_handler" line 139)
invoked from within
"rp_handler"
[19/Jun/2009:00:32:21][1424.5][-default:2-] Error: Ns_PgExec: result status: 7 message: could not receive data from server: Error 0

[19/Jun/2009:00:32:21][1424.5][-default:2-] Error: Tcl exception:
Database operation "0or1row" failed
(exception ERROR, "could not receive data from server: Error 0
")

while executing
"ns_pg_bind 0or1row nsdb0 {

select node_id
from host_node_map
where host = :host

}"
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec 0or1row $db $full_name $sql"
("uplevel" body line 2)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec 0or1row $db $full_name $sql]
}"
(procedure "db_string" line 27)
invoked from within
"db_string node_id { *SQL* } -default """
(procedure "rp_lookup_node_from_host" line 2)
invoked from within
"rp_lookup_node_from_host $host"
(procedure "root_of_host" line 11)
invoked from within
"root_of_host [ad_host]"
(procedure "rp_filter" line 21)
invoked from within
"rp_filter preauth"
[19/Jun/2009:00:32:26][1424.11][-sched:21-] Error: Ns_PgExec: result status: 7 message: could not receive data from server: Error 0

[19/Jun/2009:00:32:26][1424.11][-sched:21-] Error: Tcl exception:
Database operation "0or1row" failed
(exception ERROR, "could not receive data from server: Error 0
")

while executing
"ns_pg_bind 0or1row nsdb0 {
select acs_sc_binding__exists_p(:contract,:impl)
}"
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec 0or1row $db $full_name $sql"
("uplevel" body line 2)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec 0or1row $db $full_name $sql]
}"
(procedure "db_string" line 27)
invoked from within
"db_string binding_exists_p {*SQL*}"
(procedure "acs_sc_binding_exists_p" line 3)
invoked from within
"acs_sc_binding_exists_p FtsEngineDriver $driver"
(procedure "search::indexer" line 6)
invoked from within
"search::indexer"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 30 search::indexer {} 1245385886 0 f}"
[19/Jun/2009:00:32:26][1424.12][-sched:idle1-] Notice: starting
[19/Jun/2009:00:32:26][1424.11][-sched:17-] Error: Ns_PgExec: result status: 7 message: could not receive data from server: Error 0

[19/Jun/2009:00:32:26][1424.11][-sched:17-] Error: Tcl exception:
Database operation "select" failed
(exception ERROR, "could not receive data from server: Error 0
")

while executing
"ns_pg_bind select nsdb0 {
select notification_id,
notif_subject,
notif_text,
noti..."
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec select $db $full_statement_name $sql"
("uplevel" body line 3)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set result [list]
set selection [db_exec select $db $full_statement_name $sql]

while {[db_getro..."
(procedure "db_list_of_ns_sets" line 7)
invoked from within
"db_list_of_ns_sets select_notifications {}"
(procedure "notification::sweep::sweep_notifications" line 7)
invoked from within
"notification::sweep::sweep_notifications -interval_id 641 -batched_p 0"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 60 notification::sweep::sweep_notifications {-interval_id 641 -batched_p 0} 1245385886 0 f}"
message type 0x44 arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle
message type 0x54 arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle
message type 0x54 arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle
message type 0x54 arrived from server while idle
message type 0x44 arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle
message type 0x54 arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle
[19/Jun/2009:00:32:26][1424.12][-sched:12-] Error: Ns_PgExec: result status: 7 message: could not receive data from server: Error 0

[19/Jun/2009:00:32:26][1424.12][-sched:12-] Error: Tcl exception:
Database operation "select" failed
(exception ERROR, "could not receive data from server: Error 0
")

while executing
"ns_pg_bind select nsdb0 {
select
message_id as id,
creation_date,
locking_server,..."
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec select $db $full_statement_name $sql"
("uplevel" body line 2)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec select $db $full_statement_name $sql]

set counter 0
while { [db_getrow $..."
(procedure "db_foreach" line 36)
invoked from within
"db_foreach get_queued_messages {} {
# check if record is already there and free to use
set return_id [db_string get_qu..."
("uplevel" body line 2)
invoked from within
"uplevel $code"
invoked from within
"with_finally -code {
db_foreach get_queued_messages {} {
# check if record is already there and free to use
..."
(procedure "acs_mail_lite::sweeper" line 8)
invoked from within
"acs_mail_lite::sweeper"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 60 acs_mail_lite::sweeper {} 1245385886 0 f}"
[19/Jun/2009:00:32:56][1424.11][-sched:21-] Error: Tcl exception:
Selection did not return a value, and no default was provided
while executing
"db_string binding_exists_p {*SQL*}"
(procedure "acs_sc_binding_exists_p" line 3)
invoked from within
"acs_sc_binding_exists_p FtsEngineDriver $driver"
(procedure "search::indexer" line 6)
invoked from within
"search::indexer"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 30 search::indexer {} 1245385886 0 f}"
[19/Jun/2009:00:33:26][1424.11][-sched:21-] Notice: dbdrv: opening database 'postgres:localhost::nen'
[19/Jun/2009:00:33:26][1424.11][-sched:21-] Notice: Opening nen on localhost
[19/Jun/2009:00:33:26][1424.12][-sched:12-] Error: Tcl exception:
undefined variable `id'
while executing
"ns_pg_bind 0or1row nsdb1 {
select message_id as id
from acs_mail_lite_queue
where message_id=:id and (locking_serv..."
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec 0or1row $db $full_name $sql"
("uplevel" body line 2)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec 0or1row $db $full_name $sql]
}"
(procedure "db_string" line 27)
invoked from within
"db_string get_queued_message {} -default -1"
("uplevel" body line 3)
invoked from within
"uplevel 1 $code_block "
("uplevel" body line 1)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec select $db $full_statement_name $sql]

set counter 0
while { [db_getrow $..."
(procedure "db_foreach" line 36)
invoked from within
"db_foreach get_queued_messages {} {
# check if record is already there and free to use
set return_id [db_string get_qu..."
("uplevel" body line 2)
invoked from within
"uplevel $code"
invoked from within
"with_finally -code {
db_foreach get_queued_messages {} {
# check if record is already there and free to use
..."
(procedure "acs_mail_lite::sweeper" line 8)
invoked from within
"acs_mail_lite::sweeper"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 60 acs_mail_lite::sweeper {} 1245385886 0 f}"
[19/Jun/2009:00:33:26][1424.11][-sched:21-] Notice: Ns_PgOpenDb(postgres): Openned connection to localhost::nen.
[19/Jun/2009:00:34:26][1424.11][-sched:21-] Error: Tcl exception:
Selection did not return a value, and no default was provided
while executing
"db_string binding_exists_p {*SQL*}"
(procedure "acs_sc_binding_exists_p" line 3)
invoked from within
"acs_sc_binding_exists_p FtsEngineDriver $driver"
(procedure "search::indexer" line 6)
invoked from within
"search::indexer"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 30 search::indexer {} 1245385886 0 f}"
[19/Jun/2009:00:34:26][1424.11][-sched:12-] Error: Tcl exception:
undefined variable `id'
while executing
"ns_pg_bind 0or1row nsdb1 {
select message_id as id
from acs_mail_lite_queue
where message_id=:id and (locking_serv..."
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec 0or1row $db $full_name $sql"
("uplevel" body line 2)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec 0or1row $db $full_name $sql]
}"
(procedure "db_string" line 27)
invoked from within
"db_string get_queued_message {} -default -1"
("uplevel" body line 3)
invoked from within
"uplevel 1 $code_block "
("uplevel" body line 1)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec select $db $full_statement_name $sql]

set counter 0
while { [db_getrow $..."
(procedure "db_foreach" line 36)
invoked from within
"db_foreach get_queued_messages {} {
# check if record is already there and free to use
set return_id [db_string get_qu..."
("uplevel" body line 2)
invoked from within
"uplevel $code"
invoked from within
"with_finally -code {
db_foreach get_queued_messages {} {
# check if record is already there and free to use
..."
(procedure "acs_mail_lite::sweeper" line 8)
invoked from within
"acs_mail_lite::sweeper"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 60 acs_mail_lite::sweeper {} 1245385886 0 f}"
[19/Jun/2009:00:35:26][1424.12][-sched:21-] Error: Tcl exception:
Selection did not return a value, and no default was provided
while executing
"db_string binding_exists_p {*SQL*}"
(procedure "acs_sc_binding_exists_p" line 3)
invoked from within
"acs_sc_binding_exists_p FtsEngineDriver $driver"
(procedure "search::indexer" line 6)
invoked from within
"search::indexer"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 30 search::indexer {} 1245385886 0 f}"
[19/Jun/2009:00:35:26][1424.12][-sched:12-] Error: Tcl exception:
undefined variable `id'
while executing
"ns_pg_bind 0or1row nsdb1 {
select message_id as id
from acs_mail_lite_queue
where message_id=:id and (locking_serv..."
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec 0or1row $db $full_name $sql"
("uplevel" body line 2)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec 0or1row $db $full_name $sql]
}"
(procedure "db_string" line 27)
invoked from within
"db_string get_queued_message {} -default -1"
("uplevel" body line 3)
invoked from within
"uplevel 1 $code_block "
("uplevel" body line 1)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec select $db $full_statement_name $sql]

set counter 0
while { [db_getrow $..."
(procedure "db_foreach" line 36)
invoked from within
"db_foreach get_queued_messages {} {
# check if record is already there and free to use
set return_id [db_string get_qu..."
("uplevel" body line 2)
invoked from within
"uplevel $code"
invoked from within
"with_finally -code {
db_foreach get_queued_messages {} {
# check if record is already there and free to use
..."
(procedure "acs_mail_lite::sweeper" line 8)
invoked from within
"acs_mail_lite::sweeper"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 60 acs_mail_lite::sweeper {} 1245385886 0 f}"
[19/Jun/2009:00:35:56][1424.12][-sched:21-] Error: Tcl exception:
Selection did not return a value, and no default was provided
while executing
"db_string binding_exists_p {*SQL*}"
(procedure "acs_sc_binding_exists_p" line 3)
invoked from within
"acs_sc_binding_exists_p FtsEngineDriver $driver"
(procedure "search::indexer" line 6)
invoked from within
"search::indexer"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 30 search::indexer {} 1245385886 0 f}"
[19/Jun/2009:00:36:26][1424.11][-sched:12-] Error: Tcl exception:
undefined variable `id'
while executing
"ns_pg_bind 0or1row nsdb1 {
select message_id as id
from acs_mail_lite_queue
where message_id=:id and (locking_serv..."
("uplevel" body line 1)
invoked from within
"uplevel $ulevel [list ns_pg_bind $type $db $sql]"
invoked from within
"db_exec 0or1row $db $full_name $sql"
("uplevel" body line 2)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec 0or1row $db $full_name $sql]
}"
(procedure "db_string" line 27)
invoked from within
"db_string get_queued_message {} -default -1"
("uplevel" body line 3)
invoked from within
"uplevel 1 $code_block "
("uplevel" body line 1)
invoked from within
"uplevel 1 $code_block "
invoked from within
"db_with_handle -dbn $dbn db {
set selection [db_exec select $db $full_statement_name $sql]

set counter 0
while { [db_getrow $..."
(procedure "db_foreach" line 36)
invoked from within
"db_foreach get_queued_messages {} {
# check if record is already there and free to use
set return_id [db_string get_qu..."
("uplevel" body line 2)
invoked from within
"uplevel $code"
invoked from within
"with_finally -code {
db_foreach get_queued_messages {} {
# check if record is already there and free to use
..."
(procedure "acs_mail_lite::sweeper" line 8)
invoked from within
"acs_mail_lite::sweeper"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 60 acs_mail_lite::sweeper {} 1245385886 0 f}"
[19/Jun/2009:00:37:56][1424.12][-sched:21-] Error: Tcl exception:
Selection did not return a value, and no default was provided
while executing
"db_string binding_exists_p {*SQL*}"
(procedure "acs_sc_binding_exists_p" line 3)
invoked from within
"acs_sc_binding_exists_p FtsEngineDriver $driver"
(procedure "search::indexer" line 6)
invoked from within
"search::indexer"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 30 search::indexer {} 1245385886 0 f}"
[19/Jun/2009:00:38:26][1424.12][-sched:21-] Warning: search::dequeue: invalid: called with object_id=1 event_date= event=
search::dequeue -object_id 1 -event_date {} -event {}
invoked from within
search::indexer
invoked from within
ad_run_scheduled_proc {t f 30 search::indexer {} 1245385886 0 f}

[19/Jun/2009:00:39:56][1424.11][-sched:21-] Error: Tcl exception:
Selection did not return a value, and no default was provided
while executing
"db_string binding_exists_p {*SQL*}"
(procedure "acs_sc_binding_exists_p" line 3)
invoked from within
"acs_sc_binding_exists_p FtsEngineDriver $driver"
(procedure "search::indexer" line 6)
invoked from within
"search::indexer"
("eval" body line 1)
invoked from within
"eval [concat [list $proc] $args]"
(procedure "ad_run_scheduled_proc" line 46)
invoked from within
"ad_run_scheduled_proc {t f 30 search::indexer {} 1245385886 0 f}"