Bug 1298571

Upon further conversation with the customer, the use-case is where RGW act as a origin for a caching CDN and the cache needs to know when to re-contact the origin to see if a newer version of an object exists. The customer wasn't aware that you can arbitrarily set headers on the objects via the application which will hint this to the cache software so there is no need for RGW to set a default header.

However, the customer did request that RGW log the X-Forwarded-For header as this is necessary for debugging and analytics where you have multiple cache front-ends all talking to multiple RGW instances. Changing the RFE subject accordingly.

I could not find any documentation how to log X-FORWARDED-FOR or X-REAL-IP addresses in the default Ceph RGW civetweb log without enabling "debug ms = 1" and "debug rgw = 20" mode.

...
2016-11-18 18:18:14.137551 7f5e93b87700  1 civetweb: 0x7f5eb00018b0: 192.168.11.11 - - [18/Nov/2016:18:18:14 -0800] "GET /auth/1.0 HTTP/1.1" 204 0 - -
...

Will this feature enable Ceph RGW civetweb logging X-FORWARDED-FOR and/or X-REAL-IP addresses by default? This will be a great feature to have since enabling debug mode will filling up the disk space rapidly.

The capability log any HTTP header (and also other server variables) selectively to the RGW ops log has merged to master here:

https://github.com/ceph/ceph/pull/12491

Backport to Jewel in progress:

https://github.com/ceph/ceph/pull/12490

This is expected to reach RHCS 2.2, as planned.

Hi Matt,

Could you share the steps to reproduce the BZ?

My understanding is that you would have to set the config options in ceph.conf as in https://github.com/ceph/ceph/pull/7639 and look for the X-Forwarded-For header in civetweb logs?

(In reply to shilpa from comment #21)
> Hi Matt,
> 
> Could you share the steps to reproduce the BZ?
> 
> My understanding is that you would have to set the config options in
> ceph.conf as in https://github.com/ceph/ceph/pull/7639 and look for the
> X-Forwarded-For header in civetweb logs?

Hi Shilpa,

No.  You need to:

1. enable usage logging
2. set a header to custom log--you can pick any header that we're actually receiving to verify;  I found http_content_md5 convenient for this
2. attach a program like nc to the output log socket on the radosgw host--if you use nc, it will stream the custom log records to stdout, and you should be able to verify the custom headers appear in a json labeled array in each matching record

Here's a snippet from my ceph.conf:
	# ops log
	rgw enable ops log = true
	rgw ops log socket path = /tmp/opslog
	#rgw log http headers = "http_x_forwarded_for, http_expect, http_content_md5"

Matt

Moving this bug to verified state. verified in ceph: 10.2.5-26.el7cp
Thanks for the clarifications Matt.

Followed steps in comment23 and observed http_content_md5 header in nc stdout as mentioned in it.

Ceph.conf params:

rgw enable ops log = true
rgw ops log socket path = /tmp/opslog
rgw enable usage log = true
rgw log http headers = "http_x_forwarded_for, http_expect, http_content_md5"

after restarting rgw service a socket created in below path

/tmp/systemd-private-459cca697e8740108d3134fb6601def2-ceph-radosgw.service-7SlMGl/tmp/opslog

nc stdout:

[ubuntu@host023 ~]$ sudo nc -U /tmp/systemd-private-459cca697e8740108d3134fb6601def2-ceph-radosgw.service-7SlMGl/tmp/opslog
[{"bucket":"client2_run3","time":"2017-02-17 06:22:22.420641Z","time_local":"2017-02-17 06:22:22.420641","remote_addr":"","user":"nfsuser","operation":"PUT","uri":"\/client2_run3\/","http_status":"200","error_code":"","bytes_sent":19,"bytes_received":0,"object_size":0,"total_time":0,"user_agent":"Boto\/2.45.0 Python\/2.7.5 Linux\/3.10.0-514.6.1.el7.x86_64","referrer":""},
{"bucket":"client2_run3","time":"2017-02-17 06:22:22.619912Z","time_local":"2017-02-17 06:22:22.619912","remote_addr":"","user":"nfsuser","operation":"PUT","uri":"\/client2_run3\/redhat1607329","http_status":"200","error_code":"","bytes_sent":0,"bytes_received":1595408,"object_size":1595408,"total_time":0,"user_agent":"Boto\/2.45.0 Python\/2.7.5 Linux\/3.10.0-514.6.1.el7.x86_64","referrer":"","http_x_headers":[{"HTTP_CONTENT_MD5":"O3T1zQdAoFgCojsBnOV5ow=="},{"HTTP_EXPECT":"100-Continue"}]},
{"bucket":"client2_run3","time":"2017-02-17 06:22:22.861734Z","time_local":"2017-02-17 06:22:22.861734","remote_addr":"","user":"nfsuser","operation":"PUT","uri":"\/client2_run3\/redhat1607330","http_status":"200","error_code":"","bytes_sent":0,"bytes_received":1595408,"object_size":1595408,"total_time":0,"user_agent":"Boto\/2.45.0 Python\/2.7.5 Linux\/3.10.0-514.6.1.el7.x86_64","referrer":"","http_x_headers":[{"HTTP_CONTENT_MD5":"O3T1zQdAoFgCojsBnOV5ow=="},{"HTTP_EXPECT":"100-Continue"}]},
{"bucket":"client2_run3","time":"2017-02-17 06:22:22.958222Z","time_local":"2017-02-17 06:22:22.958222","remote_addr":"","user":"nfsuser","operation":"PUT","uri":"\/client2_run3\/redhat1607331","http_status":"200","error_code":"","bytes_sent":0,"bytes_received":1595408,"object_size":1595408,"total_time":0,"user_agent":"Boto\/2.45.0 Python\/2.7.5 Linux\/3.10.0-514.6.1.el7.x86_64","referrer":"","http_x_headers":[{"HTTP_CONTENT_MD5":"O3T1zQdAoFgCojsBnOV5ow=="},{"HTTP_EXPECT":"100-Continue"}]},
{"bucket":"client2_run3","time":"2017-02-17 06:22:23.107756Z","time_local":"2017-02-17 06:22:23.107756","remote_addr":"","user":"nfsuser","operation":"PUT","uri":"\/client2_run3\/redhat1607332","http_status":"200","error_code":"","bytes_sent":0,"bytes_received":1595408,"object_size":1595408,"total_time":0,"user_agent":"Boto\/2.45.0 Python\/2.7.5 Linux\/3.10.0-514.6.1.el7.x86_64","referrer":"","http_x_headers":[{"HTTP_CONTENT_MD5":"O3T1zQdAoFgCojsBnOV5ow=="},{"HTTP_EXPECT":"100-Continue"}]},

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2017-0514.html