Forum OpenACS Development: install issue due to silent error
The installation process worked 21 July.
For the last couple of days (at least) the following occurs during installation on ubuntu 14.04 LTS using the scripts at http://github.com/gustafn/install-ns and on freebsd10 using a modified script.
Server starts fine.
After entering initial config the following page looks like this:
-- snip --
OpenACS Installation
Installing the OpenACS kernel data model...
CREATE VIEW
..
0
(1 row)
acs_privilege__add_child
--------------------------
0
(1 row)
Done installing the OpenACS kernel data model.
Installing Kernel 5.8.1d5
Installed Kernel, version 5.8.1d5.
Package enabled.
Loading package .info files.
Done loading package .info files
Installing OpenACS Core Services
At least one core package has an unsatisifed dependency. No packages have been installed. Here's what the APM has computed:
{acs-api-browser /var/www/oacs-5-8b/packages/acs-api-browser/acs-api-browser.info {} {} {{acs-api-browser 5.8.1d2}} {{acs-kernel 5.8.1d1}} t {Package satisfies dependencies.}} {acs-automated-testing /var/www/oacs-5-8b/packages/acs-automated-testing/acs-automated-testing.info {} {} {{acs-automated-testing 5.8.1d2}} {{acs-kernel 5.8.1d1}} t {Package satisfies dependencies.}} {acs-bootstrap-installer /var/www/oacs-5-8b/packages/acs-bootstrap-installer/acs-bootstrap-installer.info {} {} {{acs-bootstrap-installer 5.8.1d3}} {{acs-kernel 5.8.1d1}} t {Package satisfies dependencies.}} {acs-reference /var/www/oacs-5-8b/packages/acs-reference/acs-reference.info {} {} {{acs-reference 5.8.1d2}} {{acs-kernel 5.8.1d1}} t {Package satisfies dependencies.}} {acs-service-contract /var/www/oacs-5-8b/packages/acs-service-contract/acs-service-contract.info {} {} {{acs-service-contract 5.8.1d2}} {{acs-kernel 5.8.1d1}} t {Package satisfies dependencies.}} {acs-templating /var/www/oacs-5-8b/packages/acs-templating/acs-templating.info {} {} {{acs-templating 5.8.1d2}} {{acs-kernel 5.8.1d1}} t {Package satisfies dependencies.}} {acs-translations /var/www/oacs-5-8b/packages/acs-translations/acs-translations.info {} {} {{acs-translations 5.8.1d2}} {} t {Package satisfies dependencies.}} {acs-tcl /var/www/oacs-5-8b/packages/acs-tcl/acs-tcl.info {} {} {{acs-tcl 5.8.1d6}} {{acs-bootstrap-installer 5.8.1d1} {acs-kernel 5.8.1d1}} t {Package satisfies dependencies.}} {ref-countries /var/www/oacs-5-8b/packages/ref-countries/ref-countries.info {} {} {{ref-countries 5.8.1d2}} {{acs-kernel 5.8.1d1} {acs-reference 5.8.1d1}} t {Package satisfies dependencies.}} {ref-language /var/www/oacs-5-8b/packages/ref-language/ref-language.info {} {} {{ref-language 5.8.1d2}} {{acs-kernel 5.8.1d1} {acs-reference 5.8.1d1}} t {Package satisfies dependencies.}} {ref-timezones /var/www/oacs-5-8b/packages/ref-timezones/ref-timezones.info {} {} {{ref-timezones 5.8.1d2}} {{acs-kernel 5.8.1d1} {acs-reference 5.8.1d1}} t {Package satisfies dependencies.}} {search /var/www/oacs-5-8b/packages/search/search.info {} {} {{search 5.8.1d3}} {{acs-service-contract 5.8.1d1}} t {Package satisfies dependencies.}} {acs-content-repository /var/www/oacs-5-8b/packages/acs-content-repository/acs-content-repository.info {} {} {{acs-content-repository 5.8.1d6}} {{acs-kernel 5.8.1d1} {acs-service-contract 5.8.1d1} {search 5.8.1d1}} t {Package satisfies dependencies.}} {acs-core-docs /var/www/oacs-5-8b/packages/acs-core-docs/acs-core-docs.info {} {} {{acs-core-docs 5.8.1d1}} {{acs-kernel 5.8.1d1} {acs-tcl 5.8.1d1}} t {Package satisfies dependencies.}} {acs-lang /var/www/oacs-5-8b/packages/acs-lang/acs-lang.info {} {} {{acs-lang 5.8.1d3}} {{acs-kernel 5.8.1d1} {acs-translations 5.8.1d1} {ref-countries 5.8.1d1} {ref-language 5.8.1d1} {ref-timezones 5.8.1d1}} t {Package satisfies dependencies.}} {acs-admin /var/www/oacs-5-8b/packages/acs-admin/acs-admin.info {} {} {{acs-admin 5.8.1d3}} {{acs-kernel 5.8.1d1} {acs-mail-lite 5.8.1d1}} f {{Requires acs-mail-lite of version >= 5.8.1d1.}}} {acs-authentication /var/www/oacs-5-8b/packages/acs-authentication/acs-authentication.info {} {} {{acs-authentication 5.8.1d2}} {{acs-kernel 5.8.1d1} {acs-service-contract 5.8.1d1} {acs-mail-lite 5.8.1d1}} f {{Requires acs-service-contract of version >= 5.8.1d1.} {Requires acs-mail-lite of version >= 5.8.1d1.}}} {acs-messaging /var/www/oacs-5-8b/packages/acs-messaging/acs-messaging.info {} {} {{acs-messaging 5.8.1d1}} {{acs-content-repository 5.8.1d1} {acs-kernel 5.8.1d1} {acs-mail-lite 5.8.1d1}} f {{Requires acs-content-repository of version >= 5.8.1d1.} {Requires acs-mail-lite of version >= 5.8.1d1.}}} {acs-subsite /var/www/oacs-5-8b/packages/acs-subsite/acs-subsite.info {} {} {{acs-subsite 5.8.1d3}} {{acs-authentication 5.8.1d1} {acs-content-repository 5.8.1d1} {acs-kernel 5.8.1d1} {acs-lang 5.8.1d1} {acs-mail-lite 5.8.1d1} {acs-tcl 5.8.1d1}} f {{Requires acs-authentication of version >= 5.8.1d1.}}} {openacs-default-theme /var/www/oacs-5-8b/packages/openacs-default-theme/openacs-default-theme.info {} {} {{openacs-default-theme 5.8.1d2}} {{acs-subsite 5.8.1d1}} f {{Requires acs-subsite of version >= 5.8.1d1.}}}
-- snip --
Log file shows only this warning:
[07/Aug/2014:16:21:23][3433.7f85ab293740][-main-] Warning: nsmain: rl_cur > FD_SETSIZE
and only this error:
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: ***Installing Kernel 5.8.1d5
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Installed Kernel, version 5.8.1d5.
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Package enabled.
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: apm_scan_packages: Scanning for new unregistered packages...
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Skipping the directory "CVS".
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-tcl init file utilities-init.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-tcl init file site-nodes-init.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/apm-callback-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/application-group-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/approval-expiration-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/attribute-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/callback-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/email-image-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/group-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/group-type-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/package-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/party-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/plpgsql-utility-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/plsql-utility-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/rel-segments-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/rel-types-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/relation-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/subsite-callback-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/subsite-navigation-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Loading acs-subsite/tcl/subsite-procs.tcl
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: apm_scan_packages: Scanning for new unregistered packages...
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Notice: Skipping the directory "CVS".
[07/Aug/2014:16:22:04][3433.7f8597efe700][-conn:oacs-5-8b:1] Error: Error sourcing /var/www/oacs-5-8b/packages/acs-bootstrap-installer/installer/install.tcl:
invalid command name "auth::create_local_account_helper"
while executing
"auth::create_local_account_helper $email $first_names $last_name $password "" "" "" "t" "approved" "" $username "
("uplevel" body line 16)
invoked from within
"uplevel 1 $transaction_code "
(procedure "db_transaction" line 1)
invoked from within
"db_transaction {
# Can't use auth::create_user
# Operation GetParameters is not implemented in 'local' implementation of contract 'auth_r..."
invoked from within
"if { ![db_string user_exists {
select count(*) from parties where email = lower(:email)
}] } {
db_transaction {
# Can't use auth::crea..."
(file "/var/www/oacs-5-8b/packages/acs-bootstrap-installer/installer/install.tcl" line 58)
invoked from within
"source $__file "
I suspected environmental variables, but a working and nonworking share the same ubuntu, only differing in the config.tcl file and oacs-5-8 files from cvs.
After setting debug to true in ns config.tcl files, I wrote a little tcl to lob off the first 42 characters of each error.log file for the length of the problem case (plus a few lines) and edited both instances (cases) to appear to use 'oacs-5-8' to minimize changes.
Here's the diff between the two error.log files:
155c155 < [-main-] Dev: config: ns/server/oacs-5-8/module/nssock:port value=8000 min=0 max=65535 default=80 (int) --- > [-main-] Dev: config: ns/server/oacs-5-8/module/nssock:port value=8002 min=0 max=65535 default=80 (int) 192a193 > [-main-] Notice: 'ns_info tcllib ' is deprecated. Use 'ns_server ?-server s? tcllib' instead. 195d195 < [-main-] Notice: bootstrap begin encoding utf-8 216c216 < [-main-] Debug: 0x2596360 convert type none to sql < select count(*) from pg_class> --- > [-main-] Debug: 0x21f8b40 convert type none to sql < select count(*) from pg_class> 325d324 < [-main-] Notice: Loading acs-tcl/tcl/http-client-procs.tcl 354c353 < [-main-] Debug: nsproxy: slave 13439 started --- > [-main-] Debug: nsproxy: slave 14069 started 388c387 < [-main-] Debug: 0x2bcf7a0 convert type none to sql < --- > [-main-] Debug: 0x280d1b0 convert type none to sql < 403,465d401 < [-main-] Debug: NO FULLQUERY FOR dbqd.acs-tcl.tcl.00-database-procs.db_table_exists.table_count --> using default SQL < [-main-] Debug: 0x2bcf7a0 REUSE sql < [-main-] Notice: nsdbpg: Querying ' < ass < e_nodes') and < relkind = 'r';' < [-main-] Notice: dbinit: sql(localhost::oacs-5-8): ' < ass < e_nodes') and < relkind = 'r' < < [-main-] Debug: db_exec: timing 0 seconds nsdb0 0or1row dbqd.acs-tcl.tcl.00-database-procs.db_table_exists.table_count < [-main-] Debug: 0x2bcc4a0 convert type none to sql < < < < < < [-main-] Notice: nsdbpg: Querying ' < < < < [-main-] Notice: dbinit: sql(localhost::oacs-5-8): ' < < < < < [-main-] Debug: db_exec: timing 0 seconds nsdb0 0or1row dbqd.acs-tcl.tcl.apm-procs.apm_package_installed_p_not_cached.apm_package_installed_p < [-main-] Debug: 0x2bcad00 convert type none to sql < < < < < < y_privilege_map m, users u, acs_magic_objects amo < amo.object_id < curity_context_root' < .user_id < 'admin') < < < [-main-] Notice: nsdbpg: Querying ' < < < < < y_privilege_map m, users u, acs_magic_objects amo < amo.object_id < curity_context_root' < .user_id < 'admin');' < [-main-] Notice: dbinit: sql(localhost::oacs-5-8): ' < < < < < y_privilege_map m, users u, acs_magic_objects amo < amo.object_id < curity_context_root' < .user_id < 'admin') < < < [-main-] Debug: db_exec: timing 0 seconds nsdb0 0or1row dbqd.acs-tcl.tcl.acs-kernel-procs.ad_acs_administrator_exists_p.admin_exists_p < [-main-] Debug: Verifying Installation: Kernel Installed? 1 An Administrator? 0 468c404,405 < [-main-] Notice: Sourcing files for postload.. tcllib = '/var/www/oacs-5-8/tcl' --- > [-main-] Notice: 'ns_info tcllib ' is deprecated. Use 'ns_server ?-server s? tcllib' instead. > [-main-] Notice: Sourcing files for postload... tcllib == '/var/www/oacs-5-8/tcl' 483,488c420,425 < [-main-] Debug: ns:interptrace[oacs-5-8]: create p:0x7f297906d4a0 a:(nil) < [-main-] Debug: ns:interptrace[oacs-5-8]: create p:0x7f297906d4a0 a:(nil) < [-main-] Debug: ns:interptrace[oacs-5-8]: create p:0x7f297906d4a0 a:(nil) < [-main-] Debug: ns:interptrace[oacs-5-8]: create nsdb:initinterp a:0x122a890 < [-main-] Debug: ns:interptrace[oacs-5-8]: create nsproxy:initinterp a:0x22c1fb0 < [-main-] Debug: ns:interptrace[oacs-5-8]: create p:0x7f29708de1e0 a:0x22c1f30 --- > [-main-] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54bef794a0 a:(nil) > [-main-] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54bef794a0 a:(nil) > [-main-] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54bef794a0 a:(nil) > [-main-] Debug: ns:interptrace[oacs-5-8]: create nsdb:initinterp a:0xe85890 > [-main-] Debug: ns:interptrace[oacs-5-8]: create nsproxy:initinterp a:0x1f83560 > [-main-] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54b687f1e0 a:0x1f834e0 497,500d433 < [-driver:nssock-] Notice: nssock: listening on 200.46.204.54:8000 < [-driver:nssock-] Notice: driver: accepting connections < [-main-] Notice: nsmain: NaviServer/4.99.6 running < [-main-] Notice: nsmain: security info: uid=1001, euid=1001, gid=1001, egid=1001 502a436,439 > [-driver:nssock-] Notice: nssock: listening on 200.46.204.54:8002 > [-main-] Notice: nsmain: NaviServer/4.99.6 running > [-main-] Notice: nsmain: security info: uid=1001, euid=1001, gid=1001, egid=1001 > [-driver:nssock-] Notice: driver: accepting connections 506,512d442 < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create nslog:initinterp /var/www/oacs-5-8/log//access.log < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create p:0x7f297906d4a0 a:(nil) < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create p:0x7f297906d4a0 a:(nil) < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create p:0x7f297906d4a0 a:(nil) < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create nsdb:initinterp a:0x122a890 < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create nsproxy:initinterp a:0x22c1fb0 < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create p:0x7f29708de1e0 a:0x22c1f30 514,524c444,456 < [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create p:0x7f297906d4a0 a:(nil) < [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create p:0x7f297906d4a0 a:(nil) < [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create p:0x7f297906d4a0 a:(nil) < [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create nsdb:initinterp a:0x122a890 < [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create nsproxy:initinterp a:0x22c1fb0 < [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create p:0x7f29708de1e0 a:0x22c1f30 < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: allocate ns:tcltrace ns_init < [-conn:oacs-5-8:1] Notice: thread initialized (0.271512 secs) < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: deallocate nsproxy:cleanup a:(nil) < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: deallocate nsdb:releasehandles a:(nil) < [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: deallocate ns:tcltrace ns_cleanup --- > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create nslog:initinterp /var/www/oacs-5-8/log//access.log > [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54bef794a0 a:(nil) > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54bef794a0 a:(nil) > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54bef794a0 a:(nil) > [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54bef794a0 a:(nil) > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54bef794a0 a:(nil) > [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54bef794a0 a:(nil) > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create nsdb:initinterp a:0xe85890 > [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create nsdb:initinterp a:0xe85890 > [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create nsproxy:initinterp a:0x1f83560 > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create nsproxy:initinterp a:0x1f83560 > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54b687f1e0 a:0x1f834e0 > [-conn:oacs-5-8:0] Debug: ns:interptrace[oacs-5-8]: create p:0x7f54b687f1e0 a:0x1f834e0 526c458 < [-conn:oacs-5-8:0] Notice: thread initialized (0.275749 secs) --- > [-conn:oacs-5-8:0] Notice: thread initialized (0.300907 secs) --- > [-conn:oacs-5-8:0] Notice: thread initialized (0.300907 secs) 530,554c462,999 < [-nsproxy:reap-] Debug: nsproxy: slave 13439 closed < [-main-] Notice: nsmain: NaviServer/4.99.6 stopping < [-main-] Notice: [driver:nssock]: stopping < [-main-] Notice: server [oacs-5-8]: stopping < [-conn:oacs-5-8:0] Debug: CondTimedWait returned an unexpected result, maybe shutdown? < [-conn:oacs-5-8:1] Debug: CondTimedWait returned an unexpected result, maybe shutdown? < [-conn:oacs-5-8:1] Notice: exiting: shutdown pending < [-conn:oacs-5-8:0] Notice: exiting: shutdown pending < [-driver:nssock-] Notice: exiting < [-main-] Notice: server [oacs-5-8]: connection threads stopped < [-main-] Notice: driver: stopping writer and spooler threads < [-main-] Debug: writer1: triggering shutdown < [-writer1-] Notice: exiting < [-main-] Debug: writer0: triggering shutdown < [-writer0-] Notice: exiting < [-main-] Notice: sched: shutdown pending < [-sched-] Notice: sched: shutdown started < [-sched-] Notice: sched: shutdown complete < [-main-] Notice: [driver:nssock]: stopped < [-shutdown-] Notice: nslog: closed '/var/www/oacs-5-8/log//access.log' < [-main-] Notice: nsproxy: shutdown started < [-nsproxy:reap-] Notice: exiting < [-main-] Notice: nsproxy: shutdown complete < [-main-] Dev: config: ns/parameters:pidfile value=/var/www/oacs-5-8/log//nsd.pid (string) < [-main-] Notice: nsmain: NaviServer/4.99.6 exiting --- > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: allocate ns:tcltrace ns_init > [-conn:oacs-5-8:1] Notice: thread initialized (0.302961 secs) > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: deallocate nsproxy:cleanup a:(nil) > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: deallocate nsdb:releasehandles a:(nil) > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: deallocate ns:tcltrace ns_cleanup > [-driver:nssock-] Debug: [1] dequeue thread connPtr 0xea1080 idle 2 state 4 create 0 > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: allocate ns:tcltrace ns_init > [-conn:oacs-5-8:1] Dev: config: ns/server/oacs-5-8/adp:DefaultParser value= (string) > [-conn:oacs-5-8:1] Dev: config: ns/threads:StackSize value=1048576 (string) > [-conn:oacs-5-8:1] Debug: NO FULLQUERY FOR dbqd.acs-tcl.tcl.00-database-procs.db_table_exists.table_count --> using default SQL > [-conn:oacs-5-8:1] Debug: 0x7f54ac00f040 convert type none to sql < > ass > le_name) and > relkind = 'r' > > [-conn:oacs-5-8:1] Notice: nsdbpg: Querying ' > ass > _packages') and > relkind = 'r';' > [-conn:oacs-5-8:1] Notice: dbinit: sql(localhost::oacs-5-8): ' > ass > _packages') and > relkind = 'r' > > [-conn:oacs-5-8:1] Debug: db_exec: timing 0 seconds nsdb0 0or1row dbqd.acs-tcl.tcl.00-database-procs.db_table_exists.table_count > [-conn:oacs-5-8:1] Dev: config: ns/server/oacs-5-8/module/nssock:hostname value=q.or97.net (string) > [-conn:oacs-5-8:1] Dev: config: ns/server/oacs-5-8/module/nssock:port value=8002 (string) > [-conn:oacs-5-8:1] Debug: Ns_ConnClose 0xea1080 stream 000040 chunk 000000 via writer 000000 sockPtr 0x7f54a0001230 > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: deallocate nsproxy:cleanup a:(nil) > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: deallocate nsdb:releasehandles a:(nil) > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: deallocate ns:tcltrace ns_cleanup > [-conn:oacs-5-8:1] Debug: [1] end of job, waiting 0 current 2 idle 1 ncons 999 fromQueue 0 start 1407471277.165986 1407471277.170933 accept 0.004947 queue 0.001134 filter 0.020655 run 0.022000 netrun 0.001345 total 0.023134 > [-driver:nssock-] Debug: [1] dequeue thread connPtr 0xea1080 idle 2 state 4 create 0 > [-conn:oacs-5-8:1] Debug: ns:interptrace[oacs-5-8]: allocate ns:tcltrace ns_init > [-conn:oacs-5-8:1] Debug: NO FULLQUERY FOR dbqd.acs-tcl.tcl.00-database-procs.db_table_exists.table_count --> using default SQL > [-conn:oacs-5-8:1] Debug: 0x7f54ac00f040 REUSE sql > [-conn:oacs-5-8:1] Notice: nsdbpg: Querying ' > ass > _objects') and > relkind = 'r';' > [-conn:oacs-5-8:1] Notice: dbinit: sql(localhost::oacs-5-8): ' > ass > _objects') and > relkind = 'r' > > [-conn:oacs-5-8:1] Debug: db_exec: timing 0 seconds nsdb0 0or1row dbqd.acs-tcl.tcl.00-database-procs.db_table_exists.table_count > [-conn:oacs-5-8:1] Dev: config: ns/db/pool/pool1:User value=nsadmin (string) > [-conn:oacs-5-8:1] Dev: config: ns/db/pool/pool1:DataSource value=localhost::oacs-5-8 (string) > [-conn:oacs-5-8:1] Dev: config: ns/db/pool/pool1:Password value= (string) > [-conn:oacs-5-8:1] Dev: config: ns/db/pool/pool1:DataSource value=localhost::oacs-5-8 (string) > [-conn:oacs-5-8:1] Dev: config: ns/db/pool/pool1:Driver value=postgres (string) > [-conn:oacs-5-8:1] Dev: config: ns/db/driver/postgres:pgbin value= (string) > [-conn:oacs-5-8:1] Dev: config: ns/db/pool/pool1:DataSource value=localhost::oacs-5-8 (string) > [-conn:oacs-5-8:1] Notice: CREATE VIEW > > [-conn:oacs-5-8:1] Notice: CREATE SEQUENCE > > [-conn:oacs-5-8:1] Notice: CREATE VIEW > > [-conn:oacs-5-8:1] Notice: CREATE FUNCTION > > [-conn:oacs-5-8:1] Notice: CREATE FUNCTION > > [-conn:oacs-5-8:1] Notice: CREATE FUNCTION > > [-conn:oacs-5-8:1] Notice: CREATE FUNCTION > > [-conn:oacs-5-8:1] Notice: CREATE FUNCTION > > [-conn:oacs-5-8:1] Notice: CREATE FUNCTION > > [-conn:oacs-5-8:1] Notice: CREATE FUNCTION > > [-conn:oacs-5-8:1] Notice: CREATE FUNCTION > > [-conn:oacs-5-8:1] Notice: CREATE FUNCTION ..
The fix is trival: [1]
To recover from the broken install, do something along these lines:
dropdb -U nsadmin oacs-5-8 createdb -U nsadmin -E UNICODE oacs-5-8 psql -U nsadmin -d oacs-5-8 -tAc "create extension hstore"
On the next opportunity, i'll try to improve the error report.
all the best
-g
[1] http://cvs.openacs.org/changelog/OpenACS?cs=oacs-5-8%3Agustafn%3A20140808125705
It should be easier now to figure out, what's going on if something goes wrong....
all the best
-gustaf
It's such a luxury to work with a system that provides useful information when things break.
Thanks for the fix
General code oversight that made it difficult to identify and trace certain start-up problems. The main thing is that an issue was identified and fixed, and similar issues will be recognized (and fixed) faster.
cheers,
Ben
