Forum OpenACS Q&A: still have problem with set address and server not going beyond login screen

28: still have problem with set address and server not going beyond login screen (response to 27)

Posted by Kenneth Wyrick on 01/17/09 05:50 AM

OK. I got excited and spoke a bit too quick. Now it's back to bring up the login screen but not allowing us to do anything else. In particular register. The following is the log from when it worked to when it didn't:

Setup your own web ba16/Jan/2009:19:07:56][4468.3083184320][-main-] Notice: ns_register_proc GET /finish-component-element* rp_invoke_proc {0$
[16/Jan/2009:19:07:56][4468.3083184320][-main-] Notice: ns_register_proc POST /finish-component-element* rp_invoke_proc {$
[16/Jan/2009:19:08:00][4468.3083184320][-main-] Notice: nsmain: AOLserver/4.5.0 running
[16/Jan/2009:19:08:00][4468.3083184320][-main-] Notice: nsmain: security info: uid=33, euid=33, gid=33, egid=33
[16/Jan/2009:19:08:00][4468.3074554768][-sched-] Notice: sched: starting
[16/Jan/2009:19:08:00][4468.3083184320][-main-] Notice: driver: starting: nssock
[16/Jan/2009:19:08:00][4468.3031493520][-nssock:driver-] Notice: starting
[16/Jan/2009:19:08:00][4468.3031493520][-nssock:driver-] Notice: nssock: listening on 0.0.0.0:8000
[16/Jan/2009:19:08:36][4468.3027291024][-sched:idle0-] Notice: starting
[16/Jan/2009:19:08:45][4468.3023088528][-sched:idle1-] Notice: starting
[16/Jan/2009:19:09:20][4468.3052506000][-conn:0-] Notice: random: generating 1 seed
[16/Jan/2009:19:09:45][4468.3027291024][-sched:13-] Notice: dbdrv: opening database 'postgres:localhost:5432:dotlrn'
[16/Jan/2009:19:09:45][4468.3027291024][-sched:13-] Notice: Opening dotlrn on localhost
[16/Jan/2009:19:09:45][4468.3027291024][-sched:13-] Notice: Ns_PgOpenDb(postgres): Openned connection to localhost:5432:d$
[16/Jan/2009:20:32:23][4468.3018886032][-conn:5-] Notice: encoding: loaded: iso8859-1
Tcl_SetBooleanObj called with shared object
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: nsmain: AOLserver/4.5.0 starting
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: nsmain: security info: uid=33, euid=33, gid=33, egid=33
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: nsmain: max files: FD_SETSIZE = 1024, rl_cur = 1024, rl_max = 1024
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: encoding: loaded: utf-8
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: fastpath[dotlrn]: mapped GET /
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: fastpath[dotlrn]: mapped HEAD /
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: fastpath[dotlrn]: mapped POST /
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: adp[dotlrn]: mapped GET /*.adp
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: adp[dotlrn]: mapped HEAD /*.adp
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: adp[dotlrn]: mapped POST /*.adp
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: modload: loading '/usr/lib/aolserver4/bin/nssock.so'
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: modload: loading '/usr/lib/aolserver4/bin/nslog.so'
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: nslog: opened '/usr/share/dotlrn/log/dotlrn.log'
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: modload: loading '/usr/lib/aolserver4/bin/nssha1.so'
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: modload: loading '/usr/lib/aolserver4/bin/nscache.so'
[16/Jan/2009:20:32:28][4830.3083647168][-main-] Notice: nscache module version 1.4 server: dotlrn

snip......
....without me doing anything except logging in and trying to register from yet another computer

...the following from the end of the file 2 minutes later and some 5000 lines later of it loading all kinds of stuff

[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loading packages/lars-blogger/tcl/technorati-init.tcl...
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loaded packages/lars-blogger/tcl/technorati-init.tcl.
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loading packages/notifications/tcl/reply-sweep-init.tcl...
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loaded packages/notifications/tcl/reply-sweep-init.tcl.
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loading packages/notifications/tcl/sweep-init.tcl...
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loaded packages/notifications/tcl/sweep-init.tcl.
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loading packages/oacs-dav/tcl/oacs-dav-init.tcl...
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: OACS-DAV preauth filters loaded on /dav/*
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loaded packages/oacs-dav/tcl/oacs-dav-init.tcl.
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loading packages/rss-support/tcl/rss-generation-init.tcl...
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loaded packages/rss-support/tcl/rss-generation-init.tcl.
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loading packages/search/tcl/search-init.tcl...
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loaded packages/search/tcl/search-init.tcl.
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loading packages/xml-rpc/tcl/system-init.tcl...
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loaded packages/xml-rpc/tcl/system-init.tcl.
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loading packages/xml-rpc/tcl/validator-init.tcl...
[16/Jan/2009:20:34:25][4830.3083647168][-main-] Notice: Loaded packages/xml-rpc/tcl/validator-init.tcl.
[16/Jan/2009:20:34:34][4830.3083647168][-main-] Notice: Loading packages/news/tcl/test/news-db-test-init.tcl...
[16/Jan/2009:20:34:35][4830.3083647168][-main-] Notice: Loaded packages/news/tcl/test/news-db-test-init.tcl.
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: Bootstrap: Done loading OpenACS.
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: Sourcing files for postload...
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: Done.
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: Executing initialization code blocks...
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: Executing initialization code block filters_register in /usr/share$
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: Executing initialization code block procs_register in /usr/share/d$
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: ns_register_proc GET /grades-sheet-csv* rp_invoke_proc {0 0 0 eva$
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: ns_register_proc POST /grades-sheet-csv* rp_invoke_proc {0 0 0 ev$
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: ns_register_proc GET /finish-component-element* rp_invoke_proc {0$
[16/Jan/2009:20:34:36][4830.3083647168][-main-] Notice: ns_register_proc POST /finish-component-element* rp_invoke_proc {$
[16/Jan/2009:20:34:40][4830.3083647168][-main-] Notice: nsmain: AOLserver/4.5.0 running
[16/Jan/2009:20:34:40][4830.3083647168][-main-] Notice: nsmain: security info: uid=33, euid=33, gid=33, egid=33
[16/Jan/2009:20:34:40][4830.3075017616][-sched-] Notice: sched: starting
[16/Jan/2009:20:34:40][4830.3083647168][-main-] Notice: driver: starting: nssock
[16/Jan/2009:20:34:40][4830.3031956368][-nssock:driver-] Notice: starting
[16/Jan/2009:20:34:40][4830.3031956368][-nssock:driver-] Notice: nssock: listening on 0.0.0.0:8000

29: Re: still have problem with set address and server not going beyond login screen (response to 28)

Posted by Héctor Romojaro on 01/20/09 01:37 PM

Hi Kenneth,

It seems that the instance is restarting when you register, but there is no clue for me on the log of why is it doing this way. Does it happens every time you login, or just one time?

-- Héctor

30: Re: still have problem with set address and server not going beyond login screen (response to 29)

Posted by Kenneth Wyrick on 01/20/09 06:57 PM

Now the instance does not start automatically. When I do svc -t /etc/service/dotlrn it will stay started for a good while as i use it on the local computer. As soon as i go to another computer, bring up the splash page and try to login it crashes.

I'm wondering if there are any optimizations that could be done to affect this. I'm also wondering if this computer is powerful enough to handle the dotlrn.

MemTotal: 515212 kB
MemFree: 8876 kB
Buffers: 3116 kB
Cached: 87276 kB
SwapCached: 1116 kB
Active: 415588 kB
Inactive: 37292 kB
HighTotal: 0 kB
HighFree: 0 kB
LowTotal: 515212 kB
LowFree: 8876 kB
SwapTotal: 859436 kB
SwapFree: 856140 kB

processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 8
model name : Pentium III (Coppermine)
stepping : 10
cpu MHz : 996.778
cache size : 256 KB

I've also noticed that the /var/log/aolserver4/dotlrn/error.log

starts loading modules which tie up the system and causes it to become unreachable, temporarily.

debian:/var/log/aolserver4/dotlrn# tail error.log
[20/Jan/2009:09:24:32][3112.3083745472][-main-] Notice: ns_register_proc GET /grades-sheet-csv* rp
_invoke_proc {0 0 0 evaluation::generate_grades_sheet {}}
[20/Jan/2009:09:24:32][3112.3083745472][-main-] Notice: ns_register_proc POST /grades-sheet-csv* r
p_invoke_proc {0 0 0 evaluation::generate_grades_sheet {}}
[20/Jan/2009:09:24:32][3112.3083745472][-main-] Notice: ns_register_proc GET /finish-component-ele
ment* rp_invoke_proc {0 0 1 imsld::finish_component_element {}}
[20/Jan/2009:09:24:32][3112.3083745472][-main-] Notice: ns_register_proc POST /finish-component-el
ement* rp_invoke_proc {0 0 1 imsld::finish_component_element {}}
[20/Jan/2009:09:24:38][3112.3083745472][-main-] Notice: nsmain: AOLserver/4.5.0 running
[20/Jan/2009:09:24:38][3112.3083745472][-main-] Notice: nsmain: security info: uid=33, euid=33, gid
=33, egid=33
[20/Jan/2009:09:24:38][3112.3075115920][-sched-] Notice: sched: starting
[20/Jan/2009:09:24:38][3112.3083745472][-main-] Notice: driver: starting: nssock
[20/Jan/2009:09:24:38][3112.3032054672][-nssock:driver-] Notice: starting
[20/Jan/2009:09:24:38][3112.3032054672][-nssock:driver-] Notice: nssock: listening on 0.0.0.0:8000
debian:/var/log/aolserver4/dotlrn# tail error.log
[20/Jan/2009:09:28:28][3112.3044662160][-conn:2-] Warning: adding fs admin portlet to page - fs_adm
in_portlet
[20/Jan/2009:09:28:28][3112.3044662160][-conn:2-] Notice: Added applet:::: dotlrn_fs
[20/Jan/2009:09:28:28][3112.3044662160][-conn:2-] Notice: Added applet:::: dotlrn_forums
[20/Jan/2009:09:28:28][3112.3044662160][-conn:2-] Notice: dotlrn::mount_package: object_type apm_pa
ckage url /dotlrn/clubs/menlo1600/ object_id 5834 instance_name {Menlo 1600} package_type apm_appli
cation package_id 5834 name menlo1600 node_id 5833 directory_p t package_key dotlrn pattern_p t par
ent_id 2149
[20/Jan/2009:09:28:29][3112.3044662160][-conn:2-] Notice: Added applet:::: dotlrn_calendar
[20/Jan/2009:09:28:29][3112.3044662160][-conn:2-] Notice: Added applet:::: dotlrn_faq
[20/Jan/2009:09:28:29][3112.3044662160][-conn:2-] Notice: apm_invoke_callback_proc: invoking callba
ck after-instantiate with command news::install::after_instantiate -package_id 5982
[20/Jan/2009:09:28:29][3112.3044662160][-conn:2-] Notice: Added applet:::: dotlrn_news
[20/Jan/2009:09:28:29][3112.3044662160][-conn:2-] Notice: Added applet:::: dotlrn_static
[20/Jan/2009:09:28:30][3112.3044662160][-conn:2-] Notice: Added applet:::: dotlrn_bm
debian:/var/log/aolserver4/dotlrn#

31: This Instance Is Working Now (response to 29)

Posted by Kenneth Wyrick on 01/21/09 05:39 PM

Dear Hector,

I left the instance up all day yesterday. I hit it and hammered it at the same time from 2 different computers. Once I restarted it at the beginning it did stay up.

I shut it down late last night and fired it back up this morning. After about 10 minutes I went to the other computer and it errored. I tried it again, shortly after that and it was up. So I'm not sure that it will continue to be stable but for now, it's doing what it was intended to do.

thanks.

32: Re: still have problem with set address and server not going beyond login screen (response to 28)

Posted by Tony Wieczorek on 03/05/09 01:13 AM

I was having the same problem with the "Tcl_SetBooleanObj" error. I compiled aolserver 4.5.1 and that didn't solve the error and crashing. I wound up compiling tcl and aolserver from scratch, and my server no longer crashes. Here's exactly the method I used: http://blog.ticketboo.com/2009/02/compile-aolserver-451-on-ubuntu.html

33: Re: still have problem with set address and server not going beyond login screen (response to 32)

Posted by Stefan Sobernig on 03/18/09 06:45 PM

Tony,

Just to keep you posted. We have been in contact with the aolserver maintainer for debian for a while now. Similar incidences have been discussed over at the aolserver list, see e.g. http://article.gmane.org/gmane.comp.web.aolserver/15470.

To cut it short: the issue you encountered has to do with a fundamental conflict between the binary-level coupling of AOLServer core and its modules, on the one hand, and a packaging mechanism with dependency structuring as debian's, on the other hand. In situations of debian package *updates* (aolserver4-core, for instance), you risk running into situations that the module binaries delivered by the debian module packages (aolserver4-nscache etc.) are incompatible with the new core, causing faults of all kind. The inverse (old core, new module) might also occur but is less probable.

Anyways, the debian maintainer came up with a fix to guarantee binary compatibility of core and modules, starting with the upcoming 4.5.1, by playing an elegant trick on the debian packaging infrastructure.

Cheers
//stefan