Forum OpenACS Development: Upgrade OpenACS site from NaviServer 4.99.16 to 4.99.18 cannot find symbol "Ns_ModuleInit"

Request notifications

Tried to upgrade Naviserver on Debian 9 OpenACS Naviserver 4.99.16 site. Downloaded:
https://raw.githubusercontent.com/gustafn/install-ns/master/install-ns.sh
and ran:
sudo bash
bash install-ns.sh
bash install-ns.sh build
When finished I did:
root@martenelo:/usr/local/ns# /usr/local/ns/bin/nsd -f -u nsadmin -g nsadmin -t /usr/local/ns/conf/nsd-config.tcl
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: OpenSSL 1.1.0k  28 May 2019 initialized
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: binder: started
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nsmain: enable progress statistics for uploads >= 1048576 bytes
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nsmain: NaviServer/4.99.18 (tar-4.99.18) starting
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nsmain: security info: uid=1001, euid=1001, gid=1001, egid=1001
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nsmain: Tcl version: 8.6.9
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nsmain: max files: soft limit 1048576, hard limit 1048576
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Warning: nsmain: rl_cur (1048576) > FD_SETSIZE (1024), select() calls should not be used
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: pool default: queueLength 0 low water 0 high water 0
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nsd/init.tcl[default]: booting virtual server:  Tcl system encoding: "utf-8"
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: modload: loading module nscp from file nscp
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nscp[default]: listening on [0.0.0.0]:4080
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nscp[default]: added user: ""
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: modload: loading module nslog from file nslog
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nslog: opened '/usr/local/ns/logs/access.log'
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: modload: loading module nscgi from file nscgi
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nscgi: GET /cgi-bin -> /usr/local/ns/cgi-bin
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nscgi: POST /cgi-bin -> /usr/local/ns/cgi-bin
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: modload: loading module nssock from file nssock
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nssock:0: enable 0 spooler thread(s) 
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nssock:0: enable 1 writer thread(s) for downloads >= 1048576 bytes, bufsize=8192 bytes, HTML streaming 0
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: nx::serializer version 2.3
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: XOTcl 2.3 loaded featuring: memcount 0 profile 0 memtrace 0 assertions 1 dtrace 0 development 0
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: Using ns_cache based on NX 2.3
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: adp[default]: mapped {GET HEAD POST} /*.adp
[16/Aug/2019:16:42:32][1096.7fd579dc6700][-main-] Notice: tcl[default]: enabletclpages for {GET HEAD POST} requests
[16/Aug/2019:16:42:33][1096.7fd579dc6700][-main-] Notice: update interpreter to epoch 1, trace deallocate, time 0.095556 secs
[16/Aug/2019:16:42:33][1096.7fd579dc6700][-main-] Notice: update interpreter to epoch 1, trace none, time 0.446982 secs
[16/Aug/2019:16:42:33][1096.7fd566ffd700][-driver:nssock:0-] Notice: starting
[16/Aug/2019:16:42:33][1096.7fd566ffd700][-driver:nssock:0-] Notice: nssock:0: listening on [0.0.0.0]:8080
[16/Aug/2019:16:42:33][1096.7fd566ffd700][-driver:nssock:0-] Notice: driver: accepting connections
[16/Aug/2019:16:42:33][1096.7fd579dc6700][-main-] Notice: nsmain: NaviServer/4.99.18 (tar-4.99.18) running
[16/Aug/2019:16:42:33][1096.7fd579dc6700][-main-] Notice: nsmain: security info: uid=1001, euid=1001, gid=1001, egid=1001
[16/Aug/2019:16:42:33][1096.7fd5770b3700][-socks-] Notice: socks: starting
[16/Aug/2019:16:42:33][1096.7fd5766ac700][-sched-] Notice: sched: starting
[16/Aug/2019:16:42:33][1096.7fd579dc6700][binder] Notice: binder: stopped
[16/Aug/2019:16:42:33][1096.7fd5667fc700][-writer0-] Notice: writer0: accepting connections
[16/Aug/2019:16:42:34][1096.7fd574823700][-conn:default:2:0-] Notice: update interpreter to epoch 1, trace none, time 0.795616 secs
[16/Aug/2019:16:42:34][1096.7fd574823700][-conn:default:2:0-] Notice: thread initialized (0.821335 secs)
[16/Aug/2019:16:42:34][1096.7fd5677fe700][-conn:default:4:0-] Notice: update interpreter to epoch 1, trace none, time 0.792876 secs
[16/Aug/2019:16:42:34][1096.7fd5677fe700][-conn:default:4:0-] Notice: thread initialized (0.842181 secs)
[16/Aug/2019:16:42:34][1096.7fd575825700][-conn:default:0:0-] Notice: update interpreter to epoch 1, trace none, time 0.832891 secs
[16/Aug/2019:16:42:34][1096.7fd575825700][-conn:default:0:0-] Notice: thread initialized (0.849221 secs)
[16/Aug/2019:16:42:34][1096.7fd575024700][-conn:default:1:0-] Notice: update interpreter to epoch 1, trace none, time 0.853097 secs
[16/Aug/2019:16:42:34][1096.7fd575024700][-conn:default:1:0-] Notice: thread initialized (0.874509 secs)
[16/Aug/2019:16:42:34][1096.7fd567fff700][-conn:default:3:0-] Notice: update interpreter to epoch 1, trace none, time 0.850233 secs
[16/Aug/2019:16:42:34][1096.7fd567fff700][-conn:default:3:0-] Notice: thread initialized (0.885010 secs)
OACS site config Failed:
root@mysite:/usr/local/ns# /usr/local/ns/bin/nsd -f -u nsadmin -g nsadmin -t /usr/local/ns/config-myoacs.tcl
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: OpenSSL 1.1.0k  28 May 2019 initialized
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: binder: started
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsd.tcl: starting to read config file...
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: Use Tcl thread library /usr/local/ns/lib/thread2.8.4/libthread2.8.4.so
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsd.tcl: using threadsafe tcl: 1
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsd.tcl: finished reading config file.
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsmain: NaviServer/4.99.18 (tar-4.99.18) starting
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsmain: security info: uid=1001, euid=1001, gid=1001, egid=1001
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsmain: Tcl version: 8.6.9
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsmain: max files: soft limit 1048576, hard limit 1048576
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Warning: nsmain: rl_cur (1048576) > FD_SETSIZE (1024), select() calls should not be used
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: pool default: queueLength 90 low water 9 high water 90
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsd/init.tcl[myoacs]: booting virtual server:  Tcl system encoding: "utf-8"
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: modload: loading module nslog from file /usr/local/ns/bin/nslog.so
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nslog: opened '/var/www/myoacs/log//access.log'
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: modload: loading module nsdb from file /usr/local/ns/bin/nsdb.so
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: modload: loading module ns/db/driver/postgres from file /usr/local/ns/bin/nsdbpg.so
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsdbpg: version 2.3 loaded, based on PostgreSQL 9.6.15 and libbpq 90615
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: dbinit: set LogMinDuration for pool pool1 over 0.01 to 0.010000
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: dbinit: set LogMinDuration for pool pool2 over 0.01 to 0.010000
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: modload: loading module nsproxy from file /usr/local/ns/bin/nsproxy.so
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: modload: loading module nssock_v4 from file /usr/local/ns/bin/nssock.so
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nssock_v4:0: enable 0 spooler thread(s) 
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nssock_v4:0: enable 2 writer thread(s) for downloads >= 1024 bytes, bufsize=8192 bytes, HTML streaming 0
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: modload: loading module nsssl_v4 from file /usr/local/ns/bin/nsssl.so
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsssl_v4:0: enable 0 spooler thread(s) 
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsssl_v4:0: enable 2 writer thread(s) for downloads >= 1024 bytes, bufsize=16384 bytes, HTML streaming 0
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: OpenSSL OpenSSL 1.1.0k  28 May 2019 initialized
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsssl: disabling SSLv2
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: nsssl: version 2.1 loaded, based on OpenSSL 1.1.0k  28 May 2019
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Notice: modload: loading module libthread from file /usr/local/ns/lib/thread2.8.4/libthread2.8.4.so
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Error: modload: /usr/local/ns/lib/thread2.8.4/libthread2.8.4.so: cannot find symbol "Ns_ModuleInit": /usr/local/ns/lib/thread2.8.4/libthread2.8.4.so: undefined symbol: _Ns_ModuleInit
[16/Aug/2019:16:32:13][1062.7f06644e7700][-main-] Fatal: modload: failed to load module '/usr/local/ns/lib/thread2.8.4/libthread2.8.4.so'
[16/Aug/2019:16:32:13][1062.7f06644e7700][binder] Notice: binder: stopped
Fixed by commenting out version 2.8.2 and uncommenting 2.8.4 from subject install script:
echo "------------------------ Settings ---------------------------------------"
# Installation directory and software versions to be installed

build_dir=/usr/local/src
#build_dir=/usr/local/src/oo2
ns_install_dir=/usr/local/ns
#ns_install_dir=/usr/local/oo2
version_ns=4.99.18
#version_ns=HEAD
version_modules=${version_ns}
#version_modules=HEAD
#version_tcl=8.5.19
#version_tcl=8.6.8
version_tcl=8.6.9
version_tcllib=1.19
tcllib_dirname=tcllib
#version_thread=2.8.2
version_thread=2.8.4
version_xotcl=2.3.0
#version_xotcl=HEAD
#version_tdom=GIT
version_tdom=0.9.1
version_tdom_git="master@{2014-11-01 00:00:00}"
tdom_base=tdom-${version_tdom}
tdom_tar=${tdom_base}-src.tgz
ns_user=nsadmin
ns_group=nsadmin
with_mongo=0
with_system_malloc=0
Dear Raul,

The problem in your first posting was, that NaviServer was loading a version of the Tcl thread library, that was not compiled with AOLserver/NaviServer support (configure flag "--with-naviserver=...").

When Tcl is compiled, it installed automatically such a library without the flag and installed libthread2.8.4.so). install-ns.sh compiled libthread 2.8.2 properly and installed it, but the configure script of OpenACS grabbed the newer version.

By setting in the install-ns.sh the version, it compiled it with the proper flag, and overwrote it.... So currently, Tcl 8.6.9 needs thread library 2.8.4.

Unfortunately, one cannot specify during Tcl configure that certain bundled packages are not compiled/configured. So this needs more fiddling to improve robustness. For now, i've changed libthread per default to 2.8.4 (as you did in your second posting in the thread).

all the best
-g