Newebe not using "X-Forwarded-For" header

[Robin Bate Boerop]

I am using a reverse proxy to pass requests to a particular named
server (port 80) to a different port on the same machine. Newebe is
therefore logging all requests as having a source IP of 127.0.0.1,
despite the fact that the reverse proxy is adding the
"X-Forwarded-For" header.

Newebe should pay attention to the "X-Forwarded-For" header. Then, the
log will reveal the correct source IP for the requests.

Shall I open a Github bug report?

--
Robin

[Gelnior]

Hi Robin,

Thank you for this bug report. You can open a Github report. If you
need some specific rights, notify me.

Frank

[Robin Bate Boerop]

On 31 December 2011 13:17, Gelnior <gel...@gmail.com> wrote:
> Hi Robin,
>
>  Thank you for this bug report. You can open a Github report. If you
> need some specific rights, notify me.

Done. Thanks.

[Gelnior]

Hi Robin,

The problem may be solved in master branch : this was just a parameter
to change on Tornado server.

I don't have a good way to test if everything is ok. Could you update
your newebe then tell me if headers are correct ?

Frank

On 31 déc 2011, 18:28, Robin Bate Boerop <m...@robinbb.com> wrote:

[Robin Bate Boerop]

On 8 January 2012 19:07, Gelnior <gel...@gmail.com> wrote:
> The problem may be solved in master branch : this was just a parameter
> to change on Tornado server.
>
> I don't have a good way to test if  everything is ok. Could you update
> your newebe then tell me if headers are correct ?

Now that I am not running in Debug mode, there does not seem to be any
logging information. Is that right?

--
Robin

[Gelnior]

Ok, in production mode, logging is stored in a file named
newebe.port.log
port must be replaced by the port on which Newebe runs.

Frank


On 10 jan, 13:57, Robin Bate Boerop <m...@robinbb.com> wrote:

[Robin Bate Boerop]

On 10 January 2012 10:05, Gelnior <gel...@gmail.com> wrote:
> Ok, in production mode, logging is stored in a file named
> newebe.port.log
> port must be replaced by the port on which Newebe runs.

Frank, thanks for responding. That file does not exist anywhere in my
Newebe Git repo. Is that where I would find it? (I run "python2
newebe_server.py" from that directory.)

--
Robin

[Gelnior]

That is really weird, you should have a log file in the same directory as your executable newebe_server.py. Could you send me the list of files stored at the root of your newebe installation ?

[Robin Bate Boerop]

Sure. Here is the output of 'ls -1a':
.
..
.git
.gitignore
README.rst
__init__.py
__init__.pyc
activities
auth
contacts
core
deploy
docs
lib
newebe_server.py
news
notes
pictures
profile
settings.py
settings.pyc
static
sync
syncdb.py

[Gelnior]

This is really weird, is there any write-access restriction in this
folder ?

On 11 jan, 13:54, Robin Bate Boerop <m...@robinbb.com> wrote:

[Robin Bate Boerop]

On 11 January 2012 10:02, Gelnior <gel...@gmail.com> wrote:
> This is really weird, is there any write-access restriction in this
> folder ?

No.

Do you want me to insert some debug code somewhere? If you don't have
time to describe in email, I'll do it myself, but not soon.

--
Robin

[Gelnior]

I don't really know where to put some debug messages. Maybe try this
in newebe_server.py, before line 235:
print "debug log filename: " + log_file
print "debug log: " + log
After you can send me what is displayed.

Frank

On 11 jan, 15:16, Robin Bate Boerop <m...@robinbb.com> wrote:

[Robin Bate Boerop]

On 13 January 2012 15:09, Gelnior <gel...@gmail.com> wrote:
> I don't really know where to put some debug messages. Maybe try this
> in newebe_server.py, before line 235:
> print "debug log filename: " + log_file
> print "debug log: " + log
> After you can send me what is displayed.

After I issue "python2 newebe_server.py", those log messages are never
printed. Perhaps it is not trying to "Daemonize"?

[Robin Bate Boerop]

I changed the settings so that Debug = True, now, so that might
explain why it's now not daemonizing. Sorry for the confusion.

Here is my stdout:
[INFO] 2012-01-14 00:37:56,398: Sets up application server.
[INFO] 2012-01-14 00:38:33,307: 200 GET / (142.166.189.94) 72.42ms
[INFO] 2012-01-14 00:38:33,405: 200 GET
/static/platform/styles/common.css (127.0.0.1) 16.79ms
[INFO] 2012-01-14 00:38:33,435: 200 GET /static/notes/styles/notes.css
(142.166.189.94) 0.79ms
[INFO] 2012-01-14 00:38:33,436: 200 GET
/static/contacts/styles/contacts.css (142.166.189.94) 0.55ms
[INFO] 2012-01-14 00:38:33,439: 200 GET
/static/profile/styles/profile.css (142.166.189.94) 0.66ms
[INFO] 2012-01-14 00:38:33,445: 200 GET
/static/activities/styles/activities.css (142.166.189.94) 0.75ms
[INFO] 2012-01-14 00:38:33,446: 200 GET /static/news/styles/news.css
(142.166.189.94) 0.56ms
[INFO] 2012-01-14 00:38:33,456: 200 GET
/static/pictures/styles/pictures.css (127.0.0.1) 0.86ms
[INFO] 2012-01-14 00:38:33,481: 200 GET
/static/css/jquery-ui-black-tie.css (127.0.0.1) 1.00ms
[INFO] 2012-01-14 00:38:33,483: 200 GET /static/css/fileuploader.css
(127.0.0.1) 0.65ms
[INFO] 2012-01-14 00:38:33,486: 200 GET /static/js/jquery.js (127.0.0.1) 1.21ms
[INFO] 2012-01-14 00:38:33,495: 200 GET /static/js/jqueryui.js
(127.0.0.1) 2.30ms
[INFO] 2012-01-14 00:38:33,496: 200 GET /static/js/date.js (127.0.0.1) 0.74ms
[INFO] 2012-01-14 00:38:33,501: 200 GET /static/js/json2.js (127.0.0.1) 0.77ms
[INFO] 2012-01-14 00:38:33,533: 200 GET /static/js/underscore.js
(127.0.0.1) 0.78ms
[INFO] 2012-01-14 00:38:33,584: 200 GET /static/js/backbone.js
(127.0.0.1) 1.39ms
[INFO] 2012-01-14 00:38:33,588: 200 GET /static/js/showdown.js
(127.0.0.1) 1.21ms
[INFO] 2012-01-14 00:38:33,602: 200 GET /static/js/fileuploader.js
(127.0.0.1) 1.07ms
[INFO] 2012-01-14 00:38:33,604: 200 GET /static/js/jasmine.js (127.0.0.1) 1.20ms
[INFO] 2012-01-14 00:38:33,695: 200 GET /static/js/jasmine-html.js
(127.0.0.1) 0.74ms
[INFO] 2012-01-14 00:38:33,697: 200 GET /static/css/jasmine.css
(127.0.0.1) 0.55ms
[INFO] 2012-01-14 00:38:33,722: 200 GET /static/news/app/news.dev.js
(127.0.0.1) 0.92ms
[INFO] 2012-01-14 00:38:33,740: 200 GET
/static/platform/app/platform.dev.js (127.0.0.1) 1.16ms
[INFO] 2012-01-14 00:38:34,135: 200 GET /static/images/clock_32.png
(127.0.0.1) 0.75ms
[INFO] 2012-01-14 00:38:34,199: 200 GET /news/microposts/all/
(127.0.0.1) 63.27ms
[INFO] 2012-01-14 00:38:34,200: 200 GET
/static/css/images/ui-bg_glass_40_111111_1x400.png (127.0.0.1) 0.65ms
[INFO] 2012-01-14 00:38:34,201: 200 GET
/static/css/images/ui-bg_highlight-hard_100_f9f9f9_1x100.png
(127.0.0.1) 0.60ms
[INFO] 2012-01-14 00:38:34,245: Long polling incoming
[INFO] 2012-01-14 00:38:35,149: 200 GET /favicon.ico (127.0.0.1) 0.76ms
[INFO] 2012-01-14 00:39:24,190: Long polling incoming
[ERROR] 2012-01-16 04:11:32,342: Exception after headers written
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/web.py",
line 897, in wrapper
return callback(*args, **kwargs)
File "../newebe/news/handlers.py", line 51, in on_new_post
self.finish()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/web.py",
line 641, in finish
self.request.finish()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/httpserver.py",
line 418, in finish
self.connection.finish()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/httpserver.py",
line 186, in finish
self._finish_request()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/httpserver.py",
line 220, in _finish_request
self.stream.read_until(b("\r\n\r\n"), self._header_callback)
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/iostream.py",
line 160, in read_until
self._check_closed()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/iostream.py",
line 504, in _check_closed
raise IOError("Stream is closed")
IOError: Stream is closed
[ERROR] 2012-01-16 04:11:32,346: Exception after headers written
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/web.py",
line 897, in wrapper
return callback(*args, **kwargs)
File "../newebe/news/handlers.py", line 51, in on_new_post
self.finish()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/web.py",
line 641, in finish
self.request.finish()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/httpserver.py",
line 418, in finish
self.connection.finish()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/httpserver.py",
line 186, in finish
self._finish_request()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/httpserver.py",
line 220, in _finish_request
self.stream.read_until(b("\r\n\r\n"), self._header_callback)
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/iostream.py",
line 160, in read_until
self._check_closed()
File "/usr/lib/python2.7/site-packages/tornado-2.1.1-py2.7.egg/tornado/iostream.py",
line 504, in _check_closed
raise IOError("Stream is closed")
IOError: Stream is closed
[INFO] 2012-01-16 04:11:32,346: Micropost from Pierre recieved
[INFO] 2012-01-16 04:11:32,347: 201 POST /news/microposts/contacts/
(82.244.52.176) 208.73ms
[INFO] 2012-01-16 06:01:55,414: Micropost from aurelien recieved
[INFO] 2012-01-16 06:01:55,415: 201 POST /news/microposts/contacts/
(87.50.19.150) 503.49ms

[Gelnior]

Good, despite of these ugly exceptions, IP addresses look to be well
displayed now. Do you think it's OK to close the ticket related to
that ?

Frank

On 16 jan, 12:47, Robin Bate Boerop <m...@robinbb.com> wrote:
> On 14 January 2012 00:40, Robin Bate Boerop <m...@robinbb.com> wrote:
>

[Robin Bate Boerop]

On 16 January 2012 18:49, Gelnior <gel...@gmail.com> wrote:
> Good, despite of these ugly exceptions, IP addresses look to be well
> displayed now. Do you think it's OK to close the ticket related to
> that ?

Some of the log entries do contain a (127.0.0.1), still, no?

[Gelnior]

Do you connect to your Newebe with the machine that hosts this
Newebe ?

I'm confused because because I don't understand why it works sometimes
and sometimes it does not work. If the problem was about headers, it
should fail or succeed all the time. Am I wrong ?

On 17 jan, 04:02, Robin Bate Boerop <m...@robinbb.com> wrote:

[Robin Bate Boerop]

On 18 January 2012 09:02, Gelnior <gel...@gmail.com> wrote:
> Do you connect to your Newebe with the machine that hosts this
> Newebe ?
>
> I'm confused because because I don't understand why it works sometimes
> and sometimes it does not work. If the problem was about headers, it
> should fail or succeed all the time. Am I wrong ?

The machine that hosts the Newebe instance is remote, and has IP
address beginning 97.

The machine from which I browse normally has an IP address of 142.*.

The reverse proxy which is connecting to the Newebe instance is local
to the Newebe instance, and connects via IP 127.0.0.1. However, it
uses the "X-Fowarded-For" header, which is intended to indicate to
Newebe the IP address of the client of behalf of which the proxy is
connecting. The Newebe instance definitely receives the connection
from the proxy, and not directly from my client.

Whether it fails or succeeds all the time depends on the details of
the code. One would expect working code to fail or succeed all the
time, yes.

[Gelnior]

Ok, sorry for that. My question was not well written. What I meant
was : Could you give some hints to understand why sometimes it works
(you have right IP) and why sometimes it fails (you have localhost) ?


On 18 jan, 14:15, Robin Bate Boerop <m...@robinbb.com> wrote:

[Gelnior]

Hello Robin,

I made a new change about X-Headers. Can you update your Newebe and
try again ?

This update will require that you upgrade Tornado to version 2.2
Moreover, it includes HTTPS. It requires that you creates certificate
and key with openssl :

sudo openssl genrsa -out ./server.key 1024
sudo openssl req -new -x509 -days 3650 -key ./server.key -out ./
server.crt
sudo chmod 640 server.key
sudo chown root:ssl-cert server.key

If you already have key and certificate put their both path in your
local_settings.py :

PRIVATE_KEY = "./server.key"
CERTIFICATE = "./server.crt"


Frank