Forum OpenACS Q&A: Turning off QD Logging

Collapse
1: Turning off QD Logging
Posted by Gilbert Wong on 03/29/02 06:55 AM
How do I turn off QD logging? I have all debug options off and the VERBOSE set to off in the DB section. I still get messages like this: 
Debug: QD_LOGGER = calling namespace =
Debug: QD_LOGGER = proc_name is -ad_permission_p-
...
Thanks.
Collapse
2: Response to Turning off QD Logging (response to 1)
Posted by Arjun Sanyal on 03/29/02 04:02 PM
Are you seeing the SQL and the bind vars? Are you using a current
cvs checkout or the beta?
Collapse
3: Response to Turning off QD Logging (response to 1)
Posted by Gilbert Wong on 03/29/02 05:10 PM

cvs - I'm still using the CVSROOT environment of:

setenv CVSROOT :ext:myusername@openacs.org:/cvsroot

then I do a cvs co acs-core. My copy of the code is old (from january).

The messages look like database queries (SQL, bind vars, etc.) , but there are some simple request processor messages.

On a side note, I'm also seeing error messages like this:

[29/Mar/2002:11:01:50][3621.3076][-conn0-] Error: return: failed to redirect '404': exceeded recursion limit of 3
[29/Mar/2002:11:01:50][3621.3076][-conn0-] Notice: nssock: server ready - resuming

And I believe the server is restarting.

Collapse
4: Response to Turning off QD Logging (response to 1)
Posted by Arjun Sanyal on 04/02/02 05:53 AM
Hmm. I'm at a loss. Check again that you have "ns_param debug 0" in the "ns_section ns/parameters" section.

I've been messing around with the QD's debug messages on
my dev server. I think there's a need for some action here since when debug is on the verbosity of the QD slows everything down to a crawl, but when debug is off all the SQL is still output to the log, but without the context of the fullname of the query e.g.

"dbqd.acs-tcl.tcl.acs-permissions-procs.permission::permission_p.select_permission_p"

... which tells you if the query was in a tcl library or a www page, what proc or file it was in, and, of course the name of the query.

without out this context, one sometimes has to go 'hither and yon' hunting for the query...

I'll venture to suggest 3 logging states: 1) log only warnings or higher for (near-)production sites 2) SQL + bind vars + context for normal development and 3) 2 + more stuff, but not all of the QD stuff, for when things get truly pear-shaped.

What do people think?

Collapse
5: Response to Turning off QD Logging (response to 1)
Posted by Bart Teeuwisse on 04/02/02 06:12 AM

This problem has been reported several times in the past. The settings in the nsd.tcl file make no difference. Which leads me to belief that there is a bug in the ns_log command.

However, you can turn of the QD logging by commenting out the following ns_log line in packages/acs-bootstrap-installer/tcl/40-db-query-dispatcher-procs.tcl:


proc db_qd_log {level msg} {
    # Centralized DB QD logging
    # We switch everything to debug for now
    # ns_log $level "QD_LOGGER = $msg"
}
Collapse
6: Response to Turning off QD Logging (response to 1)
Posted by Gilbert Wong on 04/02/02 10:13 PM
Bart, thanks.  That worked.  I also disabled the RP logging in:

packages/acs-tcl/tcl/request-processor-procs.tcl - rp_debug

I left the security debug messages on, but I might shut those off too since those appear a lot.  It looks like I can create a patch for these files to read the debug parameter in the nsd.tcl file to see what the debug setting is.  Is this something that people would be interested in?

Collapse
7: Response to Turning off QD Logging (response to 1)
Posted by Cynthia Kiser on 04/02/02 10:34 PM
Having the QD logging proc only write to the log file depending on setting in the nsd.tcl file would be very nice. I think from the tone of other people's comments, that is the behavior they assumed they would get. I had never assumed application logging would be controled by the nsd.tcl setting but now that someone offers, think it would be a great enhancement.
Collapse
8: Response to Turning off QD Logging (response to 1)
Posted by Bart Teeuwisse on 04/02/02 10:39 PM
My prefered solution would be to fix ns_log rather than compensating for its incorrect behavior. I lack the skills to mess with ns_log but maybe someone else could take a closer look?
Collapse
9: Response to Turning off QD Logging (response to 1)
Posted by Gilbert Wong on 04/02/02 10:41 PM
Actually, there is an acs-kernel parameter which is supposed to control the request processor debugging.  I'm not sure what debug parameter in the nsd.tcl file does.  Neither one turns off any debugging :)  Maybe we need to have more parameters for the QD and the security tokens.  Any suggestions?
Collapse
10: Response to Turning off QD Logging (response to 1)
Posted by David Walker on 04/03/02 01:31 AM
What version of aolserver are you using? tcl7 or tcl8?

ns_section "ns/parameters"
        ns_param   debug        false
I have aolserver 3.3.1+ad13 and setting the above parameter to true properly enables debug logging and setting it to false disables it.
Collapse
11: Response to Turning off QD Logging (response to 1)
Posted by Gilbert Wong on 04/03/02 01:57 AM
I am using AOLserver 3.4 (with the aD extras - nscache, nssha1, nsrewrite) and tcl 8.
Collapse
12: Response to Turning off QD Logging (response to 1)
Posted by Bart Teeuwisse on 04/03/02 02:01 AM
Dave, I'm running AOLserver/3.3.1+ad13 with nsd8 and see the same behavior as Gilbert. What are you running?
Collapse
13: Response to Turning off QD Logging (response to 1)
Posted by David Walker on 04/03/02 02:37 AM
I'm running nsd8 as well.  I can't test QD logging as the box is running
3.2.5.  However I don't see any reason the "ns_log debug" behavior should
change.

Please check the above debug parameter one more time to rule out any little
things like an extra character somewhere or a mispelling or something.

Collapse
14: Response to Turning off QD Logging (response to 1)
Posted by Richard Hamilton on 10/08/02 04:22 PM
I see that the query logging is still an issue in the 4.6 code from the CVS. My Aolserver init script has ns_param debug false, and I have tried editing the 40-db-query-dispatcher-procs.tcl file and commenting out the logging but that kills the server! Also I note that the code is different in this procedure from the 4.5 code.

Has anyone found why the logging will not switch of yet?

Collapse
15: Response to Turning off QD Logging (response to 1)
Posted by David Burch on 10/19/02 11:55 PM
This needs to be fixed before OpenACS can be considered usuable for a production site.  Just switched over to 4.5 on a 40,000 visitor/month site and got a 1GB log in a day.  nsd does not like writing to a file that large.  It consumes the resources of the machine to the point you cannot log in.  Nice:(
Collapse
16: Response to Turning off QD Logging (response to 1)
Posted by Gilbert Wong on 10/20/02 12:23 AM
I'm managing a site that gets about 2 million page views a month and the log file does fill up really quickly!  We're still running 4.5 (actually it was the 4.x beta release).  Anyway, as a temporary fix, we let newsyslog roll the -error.log files every hour.  This has kept the log file manageable.  Here's the syntax (FreeBSD box):

/usr/local/aolserver/log/openacs-4-error.log  nsadmin:nsadmin  600 2 10000 * Z