Forum OpenACS Q&A: Re: nsoracle error?

Collapse
5: Re: nsoracle error? (response to 1)
Posted by Dave Bauer on
Is there any more information about the actual error in the logs? It says Tcl Exception, but that doesn't explain what the actual problem was.
Collapse
6: Re: nsoracle error? (response to 5)
Posted by Abrantes Filho on
No, the log just show exactly that message.

I restarted AOLserver whit the parameter "set debug true" and just access the clob-test.tcl again. Here are the logs with debug parameter set to true:

[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: nsmain: AOLserver/4.5.1 starting
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: nsmain: security info: uid=30, euid=30, gid=8, egid=8
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: nsmain: max files: FD_SETSIZE = 1024, rl_cur = 8192, rl_max = 8192
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Warning: nsmain: rl_max > FD_SETSIZE
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: encoding: loaded: utf-8
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: fastpath[server1]: mapped GET /
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: fastpath[server1]: mapped HEAD /
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: fastpath[server1]: mapped POST /
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: adp[server1]: mapped GET /*.adp
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: adp[server1]: mapped HEAD /*.adp
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: adp[server1]: mapped POST /*.adp
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: modload: loading '/usr/local/aolserver/bin/nssock.so'
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: modload: loading '/usr/local/aolserver/bin/nslog.so'
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: nslog: opened '/usr/local/aolserver/servers/server1/modules/nslog/access.log'
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: modload: loading '/usr/local/aolserver/bin/nsdb.so'
[09/Aug/2012:10:12:26][14557.3074852544][-main-] Notice: modload: loading '/usr/local/aolserver/bin/nsoracle.so'
[09/Aug/2012:10:12:28][14557.3074852544][-main-] Notice: ora11 driver LobBufferSize = 32768
[09/Aug/2012:10:12:28][14557.3074852544][-main-] Notice: ora11 driver PrefetchRows = 0
[09/Aug/2012:10:12:28][14557.3074852544][-main-] Notice: ora11 driver PrefetchMemory = 0
[09/Aug/2012:10:12:29][14557.3074852544][-main-] Notice: Loaded ArsDigita Oracle Driver version 2.7, built on 15:01:46/Aug 2 2012
[09/Aug/2012:10:12:29][14557.3074852544][-main-] Notice: modload: loading '/usr/local/aolserver/bin/nscache.so'
[09/Aug/2012:10:12:29][14557.3074852544][-main-] Notice: nscache module version 1.5 server: server1
[09/Aug/2012:10:12:29][14557.3074852544][-main-] Notice: conf: [ns/server/server1]enabletclpages = 1
[09/Aug/2012:10:12:29][14557.3074852544][-main-] Notice: tcl: enabling .tcl pages
[09/Aug/2012:10:12:29][14557.3074852544][-main-] Notice: default thread pool: minthreads 5 maxthreads 20 idle 0 current 0 maxconns 100 queued 0 timeout 120 spread 20
[09/Aug/2012:10:12:30][14557.3074852544][-main-] Notice: XOTcl version 1.6.6 loaded
[09/Aug/2012:10:12:30][14557.3074852544][-main-] Notice: nsmain: AOLserver/4.5.1 running
[09/Aug/2012:10:12:30][14557.3074852544][-main-] Notice: nsmain: security info: uid=30, euid=30, gid=8, egid=8
[09/Aug/2012:10:12:30][14557.3066399600][-sched-] Notice: sched: starting
[09/Aug/2012:10:12:30][14557.3074852544][-main-] Notice: driver: starting: nssock
[09/Aug/2012:10:12:30][14557.3026250608][-default:0-] Notice: random: generating 1 seed
[09/Aug/2012:10:12:30][14557.3025226608][-nssock:driver-] Notice: starting
[09/Aug/2012:10:12:30][14557.3025226608][-nssock:driver-] Notice: nssock: listening on 200.179.110.80:84
[09/Aug/2012:10:13:09][14557.3026250608][-default:0-] Notice: dbdrv: opening database 'ora11:snw'
[09/Aug/2012:10:13:10][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'drop table markd_lob_test'
[09/Aug/2012:10:13:10][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'create table markd_lob_test (lob_id integer, chunks clob, blunks blob)'
[09/Aug/2012:10:13:10][14557.3026250608][-default:0-] Notice: SQL():
insert into markd_lob_test (lob_id, chunks)
values (0, empty_clob())
returning chunks into :1
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: CLOB # 0, length 67: This is a small lob. There are many like it, but this one is mine.
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select chunks from markd_lob_test where lob_id = 0'
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: SQL():
insert into markd_lob_test (lob_id, chunks)
values (1, empty_clob())
returning chunks into :1
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: CLOB # 0, length 0: (NULL)
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select chunks from markd_lob_test where lob_id = 1'
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: SQL():
insert into markd_lob_test (lob_id, blunks)
values (2, empty_blob())
returning blunks into :1
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: CLOB # 0, length 67: This is a small lob. There are many like it, but this one is mine.
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select blunks from markd_lob_test where lob_id = 2'
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: SQL():
insert into markd_lob_test (lob_id, blunks)
values (3, empty_blob())
returning blunks into :1
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: CLOB # 0, length 0: (NULL)
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select blunks from markd_lob_test where lob_id = 3'
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: SQL():
update markd_lob_test set chunks = empty_clob()
where lob_id = 0
returning chunks into :1
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: CLOB # 0, length 139: This is a small lob. There are many like it, but this one is mine. This is a small lob. There are many like it, but this one is mine.
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select chunks from markd_lob_test where lob_id = 0'
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: SQL():
update markd_lob_test set chunks = empty_clob()
where lob_id = 0
returning chunks into :1
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: CLOB # 0, length 1: a
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select chunks from markd_lob_test where lob_id = 0'
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: SQL():
update markd_lob_test set chunks = empty_clob()
where lob_id = 0
returning chunks into :1
[09/Aug/2012:10:13:11][14557.3026250608][-default:0-] Notice: CLOB # 0, length 0: (NULL)
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select chunks from markd_lob_test where lob_id = 0'
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): '
update markd_lob_test set chunks = empty_clob()
where lob_id = 0'
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select chunks from markd_lob_test where lob_id = 0'
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: SQL():
update markd_lob_test set blunks = empty_blob()
where lob_id = 0
returning blunks into :1
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: CLOB # 0, length 139: This is a small lob. There are many like it, but this one is mine. This is a small lob. There are many like it, but this one is mine.
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select blunks from markd_lob_test where lob_id = 0'
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: SQL():
update markd_lob_test set blunks = empty_blob()
where lob_id = 0
returning blunks into :1
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: CLOB # 0, length 1: a
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select blunks from markd_lob_test where lob_id = 0'
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: SQL():
update markd_lob_test set blunks = empty_blob()
where lob_id = 0
returning blunks into :1
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: CLOB # 0, length 0: (NULL)
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select blunks from markd_lob_test where lob_id = 0'
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): '
update markd_lob_test set blunks = empty_blob()
where lob_id = 0'
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: dbinit: sql(snw): 'select blunks from markd_lob_test where lob_id = 0'
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: SQL():
insert into markd_lob_test (lob_id, chunks)
values (100, empty_clob())
returning chunks into :1
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: CLOB # 0, file name /tmp/markd-empty.txt
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Notice: SQL(): select chunks from markd_lob_test where lob_id=100
[09/Aug/2012:10:13:12][14557.3026250608][-default:0-] Error: Tcl exception:

while executing
"ns_ora clob_get_file $db "select chunks from markd_lob_test where lob_id=100" ${empty_file_name}-back"
(file "/srv/www/aolserver/server1/www/nsoracle/clob-test.tcl" line 492)
invoked from within
"source $file"
invoked from within
"ns_sourceproc cns0 {}"

The log ends here.

As you can see, even with debug set to true, the Tcl exception message is very little informative.