Link to home
Start Free TrialLog in
Avatar of Mark
Mark

asked on

apache logFormat not working

I'm sure I must be doing something wrong. In my httpd.conf I have:

<IfModule log_config_module>
    LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined
    LogFormat "%h %l %u %t \"%r\" %>s %b" common

#    CustomLog "logs/access_log" common
    CustomLog "logs/access_log" combined
</IfModule>

Open in new window


Yet I am getting log messages in logfiles/access_log according to the "common" format, not the "combined" format. Yes, I've restarted httpd.

I'm confused! Why is the "combined" format not working? Where is it getting the "common" format from? I'm also running Tomcat. Could that be overriding the format somehow?

ServerRoot "/usr/local/apache2"
Slackware 13.37.0, kernel 2.6.37.6
Apache 2.2.9
Tomcat 6.0.14
Avatar of gheist
gheist
Flag of Belgium image

Can you confirm with "apachectl -M" that log_config module is to be loaded?
Avatar of Mark
Mark

ASKER

yes:
>/usr/local/apache2/bin/apachectl -M
Loaded Modules:
 core_module (static)
 authn_file_module (static)
 authn_default_module (static)
 authz_host_module (static)
 authz_groupfile_module (static)
 authz_user_module (static)
 authz_default_module (static)
 auth_basic_module (static)
 dumpio_module (static)
 include_module (static)
 filter_module (static)
 [b]log_config_module (static)[/b]
 env_module (static)
 unique_id_module (static)
 setenvif_module (static)
 ssl_module (static)
 mpm_prefork_module (static)
 http_module (static)
 mime_module (static)
 status_module (static)
 autoindex_module (static)
 asis_module (static)
 cgi_module (static)
 negotiation_module (static)
 dir_module (static)
 actions_module (static)
 speling_module (static)
 userdir_module (static)
 alias_module (static)
 rewrite_module (static)
 so_module (static)
 jk_module (shared)
Syntax OK

Open in new window

ASKER CERTIFIED SOLUTION
Avatar of gheist
gheist
Flag of Belgium image

Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
Avatar of Mark

ASKER

I needd to do a manual built at the time because I needed some things not in the pre-built version -- can't remember what now (installed in 2008). apachectl is using /usr/local/apache2/httpd.conf. The init script has, e.g.
case "$1" in
  'start')
    /usr/local/apache2/bin/apachectl -k start
  ;;

Open in new window

and /usr/local/apache2/bin/apachectl is set to execute:
HTTPD='/usr/local/apache2/bin/httpd'

Open in new window

I have verified (/usr/local/apache2/bin/httpd -S) that /usr/local/apache2/conf/httpd.conf is being used. If I change other parameters in that file, things do change, just not the log file format!!

I'll experiment further, meanwhile, any other ideas? (This is not important enough to try re-installing apache, plus no assurance that will make any different after doing the work)
20 releases later about 100 bugs are fixed, like 10 of them critical for security and relevant to your setup:
https://httpd.apache.org/security/vulnerabilities_22.html
If you havent got all the apache scripts installed manually in good places it could be viable to just install distribution httpd and merge config files (it provides threaded "worker" MPM which is like 100x more efficient than your prefork homebrew apache (some reservations apply)

Can you check if you dont redefine that LogFormat in multiple places?
1 can be in default configuration, then each virtualhost can re-define same names IF NEEDED (for all practical purposes that one should write own access log (CustomLog) to not pollute main access log with different format lines. Also dont repeat defaults. Probably define special log fromats for special statistics logs, leave at least on combined access log for future keeping.
Avatar of Mark

ASKER

I've checked the various other configs. We have no vhosts. There is a CustomLog defined in httpd-ssl.conf, but it is specific to logs/ssl_request_log.

I guess the thing to do is upgrade apache and see if that fixes it. Meanwhile, I'll turn off tomcat and post back results (in case ...).

Seems strange though. The logging stuff goes way back in Apache and I know I've seen it work properly in even older versions.
I can just confirm that LogFormat works on any version of apache I encountered in last 10 years. With log config module always being loaded as default.
Avatar of Mark

ASKER

Well, it just started working when I stopped and started tomcat and apache for the nth time. I have no explanation. This time I stopped tomcat, waited 12 seconds and stopped httpd -- but it said "httpd: no process". I waited 10 seconds, then restarted httpd. I then restarted tomcat 3 seconds later, and I got messages WITH browser information (see lines below).

Don't know why I had "httpd: no process" when I tried to shutdown apache - I've checked and the tomcat shutdown script does not kill httpd. It's a mystery, but at least it's working now.
157.55.39.176 - - [04/Dec/2014:23:50:13 -0500] "GET /ohprs HTTP/1.1" 302 -
157.55.39.176 - - [04/Dec/2014:23:50:13 -0500] "GET /ohprs/ HTTP/1.1" 200 21830
157.55.39.176 - - [04/Dec/2014:23:50:15 -0500] "GET / HTTP/1.1" 301 235
(apache and tomcat stopped)
(apache and tomcat restarted)
123.125.68.51 - - [04/Dec/2014:23:58:05 -0500] "GET /ohprs/downloads/newsletters/September%202012.pdf HTTP/1.1" 301 278 "-" "Mozilla/5.0 (Windows NT 6.1; rv:15.0) Gecko/20100101 Firefox/15.0.1"
123.125.68.17 - - [04/Dec/2014:23:58:08 -0500] "GET /ohprs/downloads/newsletters/September%202012.pdf HTTP/1.1" 503 323
202.46.62.199 - - [05/Dec/2014:00:00:22 -0500] "GET /ohprs/downloads/forms/20%20Retirees/minutes.jsp?agendas=Audit%20Committee HTTP/1.1" 301 311 "-" "Mozilla/5.0 (Windows; U; Windows NT 5.1; zh-CN; rv:1.9.1.2) Firefox/3.5.2"

Open in new window

Avatar of Mark

ASKER

Spoke too soon. The list below begins with the last message from the list above (line 8), and several lines following. You will notice at line 7 that it suddenly stops showing the client browser. I've done nothing but `tail -f` the access_log. Despite Heisenberg, I don't think my mere observation changed the outcome! What's up????? Now I'm really confused!

202.46.62.199 - - [05/Dec/2014:00:00:22 -0500] "GET /ohprs/downloads/forms/20%20Retirees/minutes.jsp?agendas=Audit%20Committee HTTP/1.1" 301 311 "-" "Mozilla/5.0 (Windows; U; Windows NT 5.1; zh-CN; rv:1.9.1.2) Firefox/3.5.2"
202.46.60.66 - - [05/Dec/2014:00:02:21 -0500] "GET / HTTP/1.1" 301 241 "-" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.0)"
119.63.193.194 - - [05/Dec/2014:00:03:21 -0500] "GET / HTTP/1.1" 301 241 "-" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.0)"
123.125.71.88 - - [05/Dec/2014:00:05:02 -0500] "GET / HTTP/1.1" 301 235 "-" "Mozilla/5.0 (compatible; Baiduspider/2.0; +http://www.baidu.com/search/spider.html)"
220.181.108.176 - - [05/Dec/2014:00:06:30 -0500] "GET / HTTP/1.1" 301 235 "-" "Mozilla/5.0 (compatible; Baiduspider/2.0; +http://www.baidu.com/search/spider.html)"
208.69.40.107 - - [05/Dec/2014:00:08:36 -0500] "GET /ohprs/minutes.jsp?minutes=Retirement%20Board HTTP/1.1" 200 7111
68.198.32.50 - - [05/Dec/2014:00:10:43 -0500] "GET / HTTP/1.1" 301 235
68.198.32.50 - - [05/Dec/2014:00:10:43 -0500] "GET /ohprs HTTP/1.1" 302 -
68.198.32.50 - - [05/Dec/2014:00:10:43 -0500] "GET /ohprs/ HTTP/1.1" 200 21830
68.198.32.50 - - [05/Dec/2014:00:10:44 -0500] "GET /ohprs/ohprs.css HTTP/1.1" 200 6556
68.198.32.50 - - [05/Dec/2014:00:10:44 -0500] "GET /ohprs/ohprs.js HTTP/1.1" 200 4773
68.198.32.50 - - [05/Dec/2014:00:10:44 -0500] "GET /ohprs/images/stripes.png HTTP/1.1" 200 5045

Open in new window

You log in 2 formats to same file
apachectl graceful-stop
watch "ps -ef | grep httpd"
for minute
if all processes are out restart it
if not
killall -9 httpd
and start it back.
Avatar of Mark

ASKER

Quite interesting. Indeed, after the `apachectl graceful-stop` the httpd tasks persisted. Strange that they didn't die. After killing them by-hand and restarting I got 6 httpd tasks created. When the 1st user connected I did get the browser info in the log, and another 5 httpd tasks were spawned. The next connections DID NOT show browser info. After a few minutes 3 of the original httpds are gone and 2 more appeared. Most new connections are not showing browser info in the log file.

1) Would respawns of new httpd task possibly be looking at a different httpd.conf?

2) Could it be simply that some browsers clients do not send information about themselves? (I doubt this is the case because my jsp programs can always get the User-Agent).
1) NO. But if you impatiently kill master apache they are unlikely to ever exit.
2) They are not obliged.

Your httpd is compiled with almost default configuration, yes it respawns a process for every request.

Your server is vulnerable to so called slowloris attack. One can easily DOS it by opening maximum number of connections and sending one byte on connection every 29s
Please move on to system apache version which is at least patched against this. And consider moving to worker MPM once there. (will not be hard with reverse proxy config only)
Avatar of Mark

ASKER

OK - this logging issue is more work than it deserves. Yes, I will move on to the current release, which I do have staged on another computer: Slackware 14.1/64bit, Apache 2.4.10. This is a completely vanilla, as-installed Apache; no tweaks, no builds.

My big problem with moving on is that I need tomcat and I've been told mod_jk for 64bit Slackware does not exist. That seems unbelievable to me. Do you agree? If you've got some insight on mod_jk for 64bits hop on over to question https://www.experts-exchange.com/questions/28574869/Need-64bit-mod-jk-so-for-tomcat-7-0-25-and-apache-2-4-10.html and bail me out there.

Meanwhile, I've leave this question open a day longer in case you have a parting comment.
Latest apache with slackware 13.37 is 2.2.29
it includes mod_proxy_ajp that is functional eqiovalent of mod_jk

why do you need mod_jk in first place?
Avatar of Mark

ASKER

why do you need mod_jk in first place?

Because I'm running tomcat with Apache. I've never tried using mod_proxy_ajp - not sure how that would work with tomcat. I have staged a new 64bit 14.1 distro with Apache 2.4.10 and Tomcat 8.0.15. I have located the necessary mod_jk.so at http://tomcat.apache.org/download-connectors.cgi. All that is working. I've set the LogFormat as desired. So far, it seems to be logging just fine, but there's not a lot of traffic at the moment until I turn it loose in production. I intend to do that tomorrow, so I'll leave this open to post back results.
Avatar of Mark

ASKER

After running the newer Apache 2.4.10 setup for quite a while all seems fine. Logging works as desired with UserAgent logged.

I think the new version solution solves the issue.
Not the new version. You just have to overhaul apache config sometimes.
I hope you adapted to using vendor packages in the meantime.