Forum OpenACS Q&A: Re: Starting OpenACS5.0.0+AOLServer4.x *really* slow

Collapse
Posted by Caroline Meeks on
Do you have dotLRN installed? I find my dotLRN instances are much slower to restart then my straight OACS5 ones.
Collapse
Posted by Walter Smith on
Hello. Thanks for the responses.  Marc was posting on my behalf, because the OACS 5 instance he's referring to is mine, running on his physical server.  I'm finally getting ready to let go of 3.2.5, and I'm trying to get version 5 installed and running smoothly.  These problems notwithstanding, I'm blown away by how far the toolkit has progressed.

This was actually a relatively fast restart.  It has taken as long as 45 minutes to start up this combo of OpenACS5.0.0+AOLServer4.x.  The pauses seem to happen in the same places during startup, although the whole startup process varies in length (but it's never under 10 minutes).

I don't know of any reason there would be DNS problems in this case, and dotLRN is not installed.  Following are the applications I have installed:
Bulk Mail     0.5
E-Commerce     4.6.1
Events Management     0.1d3
File Storage     5.0.0b4
General Comments     4.1
Mailing List     1.0
Notifications     5.0.0b4
Project Manager     0.25d
Search     5.0.0
Users Selection     0.1d

Below is a truncated version of my logs, which if I'm reading them correctly, show the slow-loading libraries as follows:
1) users-selection-procs.tcl took about 5:26 minutes
2) file-storage-procs.tcl took about 7 minutes
3) search-init.tcl took about 2:20 minutes.

users-selection-procs.tcl has taken as long as 20 minutes to load.

[05/Feb/2004:16:44:56][28790.134533120][-main-] Notice: nsmain: AOLserver/4.0 starting
.
.
.
[05/Feb/2004:16:48:00][28790.134533120][-main-] Notice: Loading packages/project-manager/tcl/task-procs.tcl...
[05/Feb/2004:16:48:00][28790.134533120][-main-] Notice: Loaded packages/project-manager/tcl/task-procs.tcl.
[05/Feb/2004:16:48:00][28790.134533120][-main-] Notice: Loading packages/search/tcl/search-procs.tcl...
[05/Feb/2004:16:48:00][28790.134533120][-main-] Notice: Loaded packages/search/tcl/search-procs.tcl.
[05/Feb/2004:16:48:00][28790.134533120][-main-] Notice: Loading packages/users-selection/tcl/users-selection-procs.tcl.\
..
[05/Feb/2004:16:48:00][28790.134533120][-main-] Notice: Loaded packages/users-selection/tcl/users-selection-procs.tcl.
[05/Feb/2004:16:53:26][28790.134533120][-main-] Notice: Loading packages/acs-admin/tcl/test/acs-admin-procs.tcl...
[05/Feb/2004:16:53:26][28790.134533120][-main-] Notice: Loaded packages/acs-admin/tcl/test/acs-admin-procs.tcl.
.
.
.
[05/Feb/2004:16:53:31][28790.134533120][-main-] Notice: Loading packages/acs-templating/tcl/test/spell-checker-procs.tc\
l...
[05/Feb/2004:16:53:31][28790.134533120][-main-] Notice: Loaded packages/acs-templating/tcl/test/spell-checker-procs.tcl\
.
[05/Feb/2004:16:53:31][28790.134533120][-main-] Notice: Loading packages/categories/tcl/test/categories-procs.tcl...
[05/Feb/2004:16:53:31][28790.134533120][-main-] Notice: Loaded packages/categories/tcl/test/categories-procs.tcl.
[05/Feb/2004:16:53:31][28790.134533120][-main-] Notice: Loading packages/file-storage/tcl/test/file-storage-procs.tcl..\
.
[05/Feb/2004:16:53:31][28790.134533120][-main-] Notice: Loaded packages/file-storage/tcl/test/file-storage-procs.tcl.
[05/Feb/2004:17:00:39][28790.134533120][-main-] Notice: Loading packages/acs-authentication/tcl/sync-init.tcl...
[05/Feb/2004:17:00:39][28790.134533120][-main-] Notice: Loaded packages/acs-authentication/tcl/sync-init.tcl.
.
.
.
[05/Feb/2004:17:00:56][28790.134533120][-main-] Notice: Loading packages/notifications/tcl/reply-sweep-init.tcl...
[05/Feb/2004:17:00:56][28790.134533120][-main-] Notice: Loaded packages/notifications/tcl/reply-sweep-init.tcl.
[05/Feb/2004:17:00:56][28790.134533120][-main-] Notice: Loading packages/notifications/tcl/sweep-init.tcl...
[05/Feb/2004:17:00:56][28790.134533120][-main-] Notice: Loaded packages/notifications/tcl/sweep-init.tcl.
[05/Feb/2004:17:00:56][28790.134533120][-main-] Notice: Loading packages/search/tcl/search-init.tcl...
[05/Feb/2004:17:00:56][28790.134533120][-main-] Notice: Loaded packages/search/tcl/search-init.tcl.
[05/Feb/2004:17:03:13][28790.134533120][-main-] Notice: Loading packages/acs-automated-testing/tcl/test/example-test-in\
it.tcl...
[05/Feb/2004:17:03:13][28790.134533120][-main-] Notice: Loaded packages/acs-automated-testing/tcl/test/example-test-ini\
t.tcl.
[05/Feb/2004:17:03:19][28790.134533120][-main-] Notice: Bootstrap: Done loading OpenACS.
[05/Feb/2004:17:03:19][28790.134533120][-main-] Notice: Sourcing files for postload...
[05/Feb/2004:17:03:19][28790.134533120][-main-] Notice: Done.
[05/Feb/2004:17:03:19][28790.134533120][-main-] Notice: Executing initialization code blocks...
[05/Feb/2004:17:03:19][28790.134533120][-main-] Notice: Executing initialization code block filters_register in /usr/lo\
cal/www/<mydomain>/openacs-5.0.0/packages/acs-tcl/tcl/request-processor-init.tcl
[05/Feb/2004:17:03:19][28790.134533120][-main-] Notice: Executing initialization code block procs_register in /usr/loca\
l/www/<mydomain>/openacs-5.0.0/packages/acs-tcl/tcl/request-processor-init.tcl
[05/Feb/2004:17:03:21][28790.134533120][-main-] Notice: nsmain: AOLserver/4.0 running
[05/Feb/2004:17:03:21][28790.134533120][-main-] Notice: nsmain: security info: uid=65534, euid=65534, gid=65534, egid=6\
5534
[05/Feb/2004:17:03:21][28790.134533120][-main-] Notice: nssock: listening on xxx.xxx.xxx.xxx:82
[05/Feb/2004:17:03:21][28790.134784000][-sched-] Notice: sched: starting
[05/Feb/2004:17:03:21][28790.135198720][-driver-] Notice: starting
[05/Feb/2004:17:03:21][28790.135198720][-driver-] Notice: driver: accepting connections
[05/Feb/2004:17:03:21][28790.135237632][-sched:idle0-] Notice: starting
[05/Feb/2004:17:03:21][28790.135237632][-sched:13-] Notice: acs-mail-lite: about to load qmail queue
[05/Feb/2004:17:03:21][28790.135237632][-sched:13-] Notice: queue dir = /new/*, no messages
[05/Feb/2004:17:03:21][28790.135239680][-sched:idle1-] Notice: starting
[05/Feb/2004:17:03:21][28790.135266304][-sched:idle2-] Notice: starting
[05/Feb/2004:17:03:38][28790.134959104][-conn:openacs-5.0.0::0] Notice: random: generating 1 seed

There were also a couple of warnings during startup:

[05/Feb/2004:16:45:27][28790.134533120][-main-] Warning: Multiple definition of ad_acs_kernel_id in /usr/local/www/<mydomain>/openacs-5.0.0/packages/acs-tcl/tcl/request-processor-procs.tcl and /usr/local/www/<mydomain>/opena\
cs-5.0.0/packages/acs-tcl/tcl/20-memoize-init.tcl

[05/Feb/2004:17:00:46][28790.134533120][-main-] Warning: acs-mail: ns_uuencode broken - will use the slow tcl version

Thanks!

Walter

Collapse
Posted by Jeff Davis on
If you are using postgres you might want to try turning on logging on the server side and look for queries in the startup sequence that might be causing this. Add
log_pid = true
log_statement = true
log_duration = true
log_timestamp = true
to /var/lib/postgresql/data/postgresql.conf and restart the db server.

You could also turn on debug on aolserver and then you could see more details about what is going on in those conspicuous gaps.