External App / Proxy - Error log full of access headers (?)

initiateit · Feb 5, 2020

Hopefully that makes some sense, as I have no idea what these actually are or where they are coming from. Sorry for the number of screenshots.

I have an app called Tailon which runs on port 9001 and basically streams log files via the Tail command. I have OLS with an External App configured;

Then have it proxied;

The app works and I can see the logs from the configured virtual host. The issue is that my error log has thousands of these;

Code:

GET /vfs/dist/main.js HTTP/1.1
Host: logs.initiateit.com.au
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.130 Safari/537.36
DNT: 1
Accept: */*
Referer: http://logs.initiateit.com.au/
Accept-Encoding: gzip        
Accept-Language: en-US,en;q=0.9
Cookie: io=lwQWXfi58hJb7uC7AAAD; JSESSIONID=dummy
X-Forwarded-Host: logs.initiateit.com.au
X-Forwarded-For: [REDACTED IP]

GET /ws/info?t=1580862425087 HTTP/1.1
Host: logs.initiateit.com.au
Connection: keep-alive
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.130 Safari/537.36
DNT: 1
Accept: */*
Referer: http://logs.initiateit.com.au/
Accept-Encoding: gzip        
Accept-Language: en-US,en;q=0.9
Cookie: io=lwQWXfi58hJb7uC7AAAD; JSESSIONID=dummy
X-Forwarded-Host: logs.initiateit.com.au
X-Forwarded-For: [REDACTED IP]

GET /static/favicon.ico HTTP/1.1
Host: logs.initiateit.com.au
Connection: keep-alive
Pragma: no-cache
Cache-Control: no-cache
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.130 Safari/537.36
DNT: 1
Accept: image/webp,image/apng,image/*,*/*;q=0.8
Referer: http://logs.initiateit.com.au/
Accept-Encoding: gzip        
Accept-Language: en-US,en;q=0.9
Cookie: io=lwQWXfi58hJb7uC7AAAD; JSESSIONID=dummy
X-Forwarded-Host: logs.initiateit.com.au
X-Forwarded-For: [REDACTED IP]

So many of them. My log settings are (with borth access and error set to Log Level of : ERROR.

Can anyone tell me what these things are and why they are in my error log? They dont even look like errors to me.

Thankyou for your help!

stuart.h · Feb 25, 2020

We are observing the same thing with our setup, OLS 1.6.7 running on Ubuntu 18.04 LTS as a reverse proxy.

These entries are the request headers that are forwarded on to whatever service you have OLS proxying (in your case, @initiateit, your web app). Essentially, it's the headers from the requesting application/browser with the X-Forwarded-xxx headers attached.

That covers what these things are. As for why they are in the error log? I honestly think it's a bug. I don't recall seeing them in there in the 1.5.x version of OLS and I have gone through our configuration and cannot see where or what would cause them to be logged. I could be wrong. Since these are not errors, however, they should not be logged in the error log at all. As it stands, this is leading to us generating almost 250MB of error logs per day! What's worse, these entries appear in both the server error log and the virtual host error log (if one is set).

As a note, none of these headers show up in the admin error log, presumably because no proxying occurs here. Thus, I think this is related entirely to virtual hosts configured with a proxied External App. We have no non-proxied virtual hosts to test this theory on, though.

A potential side effect of this is that the OLS built-in log viewer has become unusable as it is unable to correctly parse the error log since these entries do not fit the log structure. This is speculation on my part based on the fact that we are unable to use the log viewer in the OLS admin interface.

Here is our (redacted) httpd_config.conf:

NGINX:

serverName                xxx
user                      nobody
group                     nogroup
priority                  0
cpuAffinity               1
enableLVE                 0
inMemBufSize              500M
swappingDir               /tmp/lshttpd/swap
autoFix503                1
enableh2c                 0
gracefulRestartTimeout    300
mime                      conf/mime.properties
disableInitLogRotation    1
showVersionNumber         2
enableIpGeo               1
useIpInProxyHeader        1
adminEmails               xxxxxxxxxx

errorlog $SERVER_ROOT/logs/error.log {
  logLevel                DEBUG
  debugLevel              0
  rollingSize             10M
  enableStderrLog         1
}

accesslog $SERVER_ROOT/logs/access.log {
  logHeaders              7
  rollingSize             10M
  keepDays                30
  compressArchive         1
}
indexFiles                index.html, index.php
autoIndex                 0

expires  {
  enableExpires           1
  expiresByType           image/*=A604800,text/css=A604800,application/x-javascript=A604800,application/javascript=A604800,font/*=A604800,application/x-font-ttf=A604800
}
autoLoadHtaccess          1

geoipdb /usr/share/GeoIP/GeoLite2-Country.mmdb {
  geoipDBName             COUNTRY_DB
}

geoipdb /usr/share/GeoIP/GeoLite2-City.mmdb {
  geoipDBName             CITY_DB
}

tuning  {
  maxConnections          10000
  maxSSLConnections       10000
  connTimeout             300
  maxKeepAliveReq         10000
  keepAliveTimeout        5
  sndBufSize              0
  rcvBufSize              0
  maxReqURLLen            16384
  maxReqHeaderSize        16380
  maxReqBodySize          5118M
  maxDynRespHeaderSize    32768
  maxDynRespSize          5118M
  maxCachedFileSize       4096
  totalInMemCacheSize     20M
  maxMMapFileSize         256K
  totalMMapCacheSize      40M
  useSendfile             1
  fileETag                28
  enableGzipCompress      1
  compressibleTypes       text/*, application/x-javascript, application/xml, application/javascript, image/svg+xml,application/rss+xml
  enableDynGzipCompress   1
  gzipCompressLevel       6
  gzipAutoUpdateStatic    1
  gzipStaticCompressLevel 6
  brStaticCompressLevel   6
  gzipMaxFileSize         10M
  gzipMinFileSize         300
  sslStrongDhKey          1
  sslSessionCache         1
}

fileAccessControl  {
  followSymbolLink        1
  checkSymbolLink         0
  requiredPermissionMask  000
  restrictedPermissionMask 000
}

perClientConnLimit  {
  staticReqPerSec         0
  dynReqPerSec            0
  outBandwidth            0
  inBandwidth             0
  softLimit               10000
  hardLimit               10000
  gracePeriod             15
  banPeriod               300
}

CGIRLimit  {
  maxCGIInstances         20
  minUID                  11
  minGID                  10
  priority                0
  CPUSoftLimit            10
  CPUHardLimit            50
  memSoftLimit            1460M
  memHardLimit            1470M
  procSoftLimit           400
  procHardLimit           450
}

accessDenyDir  {
  dir                     /
  dir                     /etc/*
  dir                     /dev/*
  dir                     conf/*
  dir                     admin/conf/*
}

accessControl  {
  allow                   ALL
}

extprocessor lsphp {
  type                    lsapi
  address                 uds://tmp/lshttpd/lsphp.sock
  maxConns                10
  env                     PHP_LSAPI_CHILDREN=10
  env                     LSAPI_AVOID_FORK=200M
  initTimeout             60
  retryTimeout            0
  persistConn             1
  respBuffer              0
  autoStart               1
  path                    fcgi-bin/lsphpnew
  backlog                 100
  instances               1
  priority                0
  memSoftLimit            2047M
  memHardLimit            2047M
  procSoftLimit           1400
  procHardLimit           1500
}

scripthandler  {
  add                     lsapi:lsphp php
}

railsDefaults  {
  maxConns                1
  env                     LSAPI_MAX_IDLE=60
  initTimeout             60
  retryTimeout            0
  pcKeepAliveTimeout      60
  respBuffer              0
  backlog                 50
  runOnStartUp            3
  extMaxIdleTime          300
  priority                3
  memSoftLimit            2047M
  memHardLimit            2047M
  procSoftLimit           500
  procHardLimit           600
}

wsgiDefaults  {
  maxConns                5
  env                     LSAPI_MAX_IDLE=60
  initTimeout             60
  retryTimeout            0
  pcKeepAliveTimeout      60
  respBuffer              0
  backlog                 50
  runOnStartUp            3
  extMaxIdleTime          300
  priority                3
  memSoftLimit            2047M
  memHardLimit            2047M
  procSoftLimit           500
  procHardLimit           600
}

nodeDefaults  {
  maxConns                5
  env                     LSAPI_MAX_IDLE=60
  initTimeout             60
  retryTimeout            0
  pcKeepAliveTimeout      60
  respBuffer              0
  backlog                 50
  runOnStartUp            3
  extMaxIdleTime          300
  priority                3
  memSoftLimit            2047M
  memHardLimit            2047M
  procSoftLimit           500
  procHardLimit           600
}

module cache {
  internal                1
#          1
checkPrivateCache   1
checkPublicCache    1
maxCacheObjSize     10000000
maxStaleAge         200
qsCache             1
reqCookieCache      1
respCookieCache     1
ignoreReqCacheCtrl  1
ignoreRespCacheCtrl 0

enableCache         0
expireInSeconds     3600
enablePrivateCache  0
privateExpireInSeconds 3600
  ls_enabled              1
}

virtualhost Example {
  vhRoot                  Example/
  configFile              conf/vhosts/Example/vhconf.conf
  allowSymbolLink         1
  enableScript            1
  restrained              1
  setUIDMode              0
}

virtualhost vhostA {
  vhRoot                  $SERVER_ROOT/vhostA
  configFile              $SERVER_ROOT/conf/vhosts/$VH_NAME/vhconf.conf
  allowSymbolLink         1
  enableScript            1
  restrained              1
}

virtualhost vhsotB {
  vhRoot                  $SERVER_ROOT/vhostB
  configFile              $SERVER_ROOT/conf/vhosts/$VH_NAME/vhconf.conf
  allowSymbolLink         1
  enableScript            1
  restrained              1
}

virtualhost vhostC {
  vhRoot                  $SERVER_ROOT/vhostC
  configFile              $SERVER_ROOT/conf/vhosts/$VH_NAME/vhconf.conf
  allowSymbolLink         1
  enableScript            1
  restrained              1
}

virtualhost vhostD {
  vhRoot                  $SERVER_ROOT/vhostD
  configFile              $SERVER_ROOT/conf/vhosts/$VH_NAME/vhconf.conf
  allowSymbolLink         1
  enableScript            1
  restrained              1
}

virtualhost vhostE {
  vhRoot                  $SERVER_ROOT/vhostE
  configFile              $SERVER_ROOT/conf/vhosts/$VH_NAME/vhconf.conf
  allowSymbolLink         1
  enableScript            1
  restrained              1
}

virtualhost vhostF {
  vhRoot                  $SERVER_ROOT/vhostF
  configFile              $SERVER_ROOT/conf/vhosts/vhostF/vhconf.conf
  note                    This is the Virtual Host configuration for maintenance mode
  allowSymbolLink         1
  enableScript            0
  restrained              1
}

virtualhost vhostG {
  vhRoot                  vhostG/
  configFile              $SERVER_ROOT/conf/vhosts/$VH_NAME/vhconf.conf
  allowSymbolLink         1
  enableScript            0
  restrained              1
}

virtualhost vhostH {
  vhRoot                  $SERVER_ROOT/vhostH
  configFile              $SERVER_ROOT/conf/vhosts/$VH_NAME/vhconf.conf
  allowSymbolLink         1
  enableScript            1
  restrained              1
}

listener Default {
  address                 *:80
  secure                  0
  map                     SSLRedirect *
}

listener Defaultssl {
  address                 *:443
  secure                  1
  keyFile                 /usr/local/lsws/conf/example.key
  certFile                /usr/local/lsws/conf/example.crt
  map                     xxxxxxxx
  map                     xxxxxxxx
  map                     xxxxxxxx
  map                     xxxxxxxx
  map                     xxxxxxxx
  map                     xxxxxxxx
}

vhTemplate centralConfigLog {
  templateFile            conf/templates/ccl.conf
  listeners               Default
}

vhTemplate EasyRailsWithSuEXEC {
  templateFile            conf/templates/rails.conf
  listeners               Default
}
suspendedVhosts           vhostA,vhostF

And an example vhost file:

Code:

docRoot                   $VH_ROOT/html
vhDomain                  xxxxxx
enableGzip                1
enableIpGeo               1
cgroups                   0

errorlog $VH_ROOT/logs/error.log {
  useServer               0
  logLevel                ERROR
  rollingSize             8M
}

accesslog $VH_ROOT/logs/access.log {
  useServer               0
  logHeaders              7
  rollingSize             8M
  keepDays                14
  compressArchive         1
}

index  {
  useServer               1
  autoIndex               0
}

extprocessor ExtAppA {
  type                    proxy
  address                 <removed>
  maxConns                100
  initTimeout             120
  retryTimeout            3
  respBuffer              0
}

extprocessor ExtAppB {
  type                    proxy
  address                 <removed>
  maxConns                2000
  initTimeout             120
  retryTimeout            3
  respBuffer              0
}

context / {
  type                    proxy
  handler                 ExtAppA
  extraHeaders            Header set Strict-Transport-Security "max-age=63072000; includeSubDomains; preload"
  addDefaultCharset       off
  enableIpGeo             1
}

rewrite  {
  enable                  1
  rules                   <<<END_rules
RewriteEngine On
RewriteRule <removed>
RewriteRule <removed>
RewriteRule <removed> [END]
RewriteRule <regex removed> "http://ExtAppB/$1" [P]
  END_rules


}

vhssl  {
  keyFile                 $VH_ROOT/certs/privkey.pem
  certFile                $VH_ROOT/certs/fullchain.pem
  certChain               1
  sslProtocol             24
  DHParam                 $SERVER_ROOT/dhparam.pem
  enableSpdy              12
}

Hopefully that's enough to give the devs something to work with to resolve the issue.

stuart.h · Feb 25, 2020

initiateit said:

Just a quick note, I would redact your IP address from these logs.

You never know who's watching...

initiateit · Feb 25, 2020

stuart.h said:

We are observing the same thing with our setup, OLS 1.6.7 running on Ubuntu 18.04 LTS as a reverse proxy.

These entries are the request headers that are forwarded on to whatever service you have OLS proxying (in your case, @initiateit, your web app). Essentially, it's the headers from the requesting application/browser with the X-Forwarded-xxx headers attached.

That covers what these things are. As for why they are in the error log? I honestly think it's a bug. I don't recall seeing them in there in the 1.5.x version of OLS and I have gone through our configuration and cannot see where or what would cause them to be logged. I could be wrong. Since these are not errors, however, they should not be logged in the error log at all. As it stands, this is leading to us generating almost 250MB of error logs per day! What's worse, these entries appear in both the server error log and the virtual host error log (if one is set).

As a note, none of these headers show up in the admin error log, presumably because no proxying occurs here. Thus, I think this is related entirely to virtual hosts configured with a proxied External App. We have no non-proxied virtual hosts to test this theory on, though.

A potential side effect of this is that the OLS built-in log viewer has become unusable as it is unable to correctly parse the error log since these entries do not fit the log structure. This is speculation on my part based on the fact that we are unable to use the log viewer in the OLS admin interface.

Thanks for your reply stuart.h !

I had reached out on the official slack channel a couple of days ago and it was indicated that this was normal and I should log an issue on github to get it looked at. I completely agree that they are a nuisance - they take up disk space and consume disk writes for no gain in normal everyday usage. I logged an issue on GitHub here: https://github.com/litespeedtech/openlitespeed/issues/166

I would like to see an option to either disable them or let us define a log file to write to through the web admin.

lukasz · Mar 11, 2020

Any progress? Has anyone checked this problem in the new version (1.7)?

initiateit · Mar 11, 2020

lukasz said:

Not yet mate. Problem still exists in new version.

External App / Proxy - Error log full of access headers (?)

initiateit

New Member

stuart.h

New Member

stuart.h

New Member

initiateit

New Member

lukasz

New Member

initiateit

New Member