Server disconnected on redirect

Gigiarum · February 23, 2018, 12:38pm

I’m using redirect_requests example in mitmproxy 3.0.1 but I have a problem: not all client requests end fine because mitmproxy returns 502 Bad Gateway error with detail HttpReadDisconnect('Server disconnected',).
I am try to redirect “site-to-redirect” to “localhost:8000”. Here mitmproxy log:

2018-02-23T11:52:47 DEBUG ::ffff:192.168.3.128:63265: request
→ Request(GET site-to-redirect:80/)
2018-02-23T11:52:47 DEBUG ::ffff:192.168.3.128:63265: Set new server address: localhost:8000
2018-02-23T11:52:47 DEBUG ::ffff:192.168.3.128:63265: serverconnect
→ (‘localhost’, 8000)
2018-02-23T11:52:47 DEBUG ::ffff:192.168.3.128:63265: response
→ Response(200 OK, text/html; charset=utf-8, 1.59k)
2018-02-23T11:52:47 192.168.3.128:63265: GET http://localhost:8000/
2018-02-23T11:52:47 Host: localhost
2018-02-23T11:52:47 Proxy-Connection: keep-alive
2018-02-23T11:52:47 Cache-Control: max-age=0
2018-02-23T11:52:47 User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.132 Safari/537.36
2018-02-23T11:52:47 Upgrade-Insecure-Requests: 1
2018-02-23T11:52:47 Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,/;q=0.8
2018-02-23T11:52:47 Accept-Encoding: gzip, deflate
2018-02-23T11:52:47 Accept-Language: it-IT,it;q=0.9,en-US;q=0.8,en;q=0.7
2018-02-23T11:52:47 Cookie: PHPSESSID=f8avrseullsuhhc1p56f50rg86
2018-02-23T11:52:47 << 200 OK 1.59k
2018-02-23T11:52:47 Date: Fri, 23 Feb 2018 11:52:47 GMT
2018-02-23T11:52:47 Server: WSGIServer/0.2 CPython/3.6.3
2018-02-23T11:52:47 Content-Type: text/html; charset=utf-8
2018-02-23T11:52:47 X-Frame-Options: SAMEORIGIN
2018-02-23T11:52:47 Content-Length: 1626
2018-02-23T11:52:47 DEBUG ::ffff:192.168.3.128:63265: request
→ Request(GET site-to-redirect:80/static/bootstrap.min.css)
2018-02-23T11:52:47 ERROR Addon error: Traceback (most recent call last):
File “/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/mitmproxy/addons/termlog.py”, line 37, in log
err=(e.level == “error”)
File “/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/click/termui.py”, line 420, in secho
return echo(style(text, **styles), file=file, nl=nl, err=err, color=color)
File “/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/click/utils.py”, line 259, in echo
file.write(message)
UnicodeEncodeError: ‘ascii’ codec can’t encode character ‘\xe0’ in position 51: ordinal not in range(128)
2018-02-23T11:52:47 192.168.3.128:63265: GET http://localhost:8000/static/bootstrap.min.css
2018-02-23T11:52:47 Host: localhost
2018-02-23T11:52:47 Proxy-Connection: keep-alive
2018-02-23T11:52:47 User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.132 Safari/537.36
2018-02-23T11:52:47 Accept: text/css,/;q=0.1
2018-02-23T11:52:47 Referer: http://site-to-redirect/
2018-02-23T11:52:47 Accept-Encoding: gzip, deflate
2018-02-23T11:52:47 Accept-Language: it-IT,it;q=0.9,en-US;q=0.8,en;q=0.7
2018-02-23T11:52:47 Cookie: PHPSESSID=f8avrseullsuhhc1p56f50rg86
2018-02-23T11:52:47 << Server disconnected
2018-02-23T11:52:47 DEBUG ::ffff:192.168.3.128:63265: serverdisconnect
→ (‘localhost’, 8000)
2018-02-23T11:52:47 INFO 192.168.3.128:63265: clientdisconnect

On the server side I see only the first call endend with 200 code and nothing about the second one.

I try to call directly the bootstrap resource and it works one time yes and one time no.

2018-02-23T12:16:04 INFO 192.168.3.128:64072: clientconnect
2018-02-23T12:16:04 DEBUG ::ffff:192.168.3.128:64072: request
→ Request(GET site-to-redirect:80/static/bootstrap.min.css)
2018-02-23T12:16:04 DEBUG ::ffff:192.168.3.128:64072: Set new server address: localhost:8000
2018-02-23T12:16:04 DEBUG ::ffff:192.168.3.128:64072: serverconnect
→ (‘localhost’, 8000)
2018-02-23T12:16:04 DEBUG ::ffff:192.168.3.128:64072: response
** → Response(200 OK, text/css, 118.36k)**
2018-02-23T12:16:04 192.168.3.128:64072: GET http://localhost:8000/static/bootstrap.min.css
2018-02-23T12:16:04 Host: localhost
2018-02-23T12:16:04 Proxy-Connection: keep-alive
2018-02-23T12:16:04 Cache-Control: max-age=0
2018-02-23T12:16:04 User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.132 Safari/537.36
2018-02-23T12:16:04 Upgrade-Insecure-Requests: 1
2018-02-23T12:16:04 Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,/;q=0.8
2018-02-23T12:16:04 Accept-Encoding: gzip, deflate
2018-02-23T12:16:04 Accept-Language: it-IT,it;q=0.9,en-US;q=0.8,en;q=0.7
2018-02-23T12:16:04 Cookie: PHPSESSID=f8avrseullsuhhc1p56f50rg86
2018-02-23T12:16:04 << 200 OK 118.36k
2018-02-23T12:16:04 Date: Fri, 23 Feb 2018 12:16:04 GMT
2018-02-23T12:16:04 Server: WSGIServer/0.2 CPython/3.6.3
2018-02-23T12:16:04 Content-Type: text/css
2018-02-23T12:16:04 Last-Modified: Mon, 25 Jul 2016 14:53:28 GMT
2018-02-23T12:16:04 Content-Length: 121200
2018-02-23T12:16:05 DEBUG ::ffff:192.168.3.128:64072: request
→ Request(GET site-to-redirect:80/static/bootstrap.min.css)
2018-02-23T12:16:05 ERROR Addon error: Traceback (most recent call last):
File “/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/mitmproxy/addons/termlog.py”, line 37, in log
err=(e.level == “error”)
File “/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/click/termui.py”, line 420, in secho
return echo(style(text, **styles), file=file, nl=nl, err=err, color=color)
File “/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/click/utils.py”, line 259, in echo
file.write(message)
UnicodeEncodeError: ‘ascii’ codec can’t encode character ‘\xe0’ in position 51: ordinal not in range(128)
2018-02-23T12:16:05 192.168.3.128:64072: GET http://localhost:8000/static/bootstrap.min.css
2018-02-23T12:16:05 Host: localhost
2018-02-23T12:16:05 Proxy-Connection: keep-alive
2018-02-23T12:16:05 Cache-Control: max-age=0
2018-02-23T12:16:05 User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.132 Safari/537.36
2018-02-23T12:16:05 Upgrade-Insecure-Requests: 1
2018-02-23T12:16:05 Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,/;q=0.8
2018-02-23T12:16:05 Accept-Encoding: gzip, deflate
2018-02-23T12:16:05 Accept-Language: it-IT,it;q=0.9,en-US;q=0.8,en;q=0.7
2018-02-23T12:16:05 Cookie: PHPSESSID=f8avrseullsuhhc1p56f50rg86
2018-02-23T12:16:05 << Server disconnected
2018-02-23T12:16:05 DEBUG ::ffff:192.168.3.128:64072: serverdisconnect
→ (‘localhost’, 8000)
2018-02-23T12:16:05 INFO 192.168.3.128:64072: clientdisconnect

In my opinion it works only when I see the log Set new server address: localhost:8000 after the incoming request.

You will see timestamps because I edited addons/termlog.py file with this

import sys
import click

from mitmproxy import log
from mitmproxy import ctx

from datetime import datetime

These get over-ridden by the save execution context. Keep them around so we

can log directly.

realstdout = sys.stdout
realstderr = sys.stderr

class TermLog:
def init(self, outfile=None):
self.outfile = outfile

def log(self, e):
    if log.log_tier(e.level) == log.log_tier("error"):
        outfile = self.outfile or realstderr
    else:
        outfile = self.outfile or realstdout

    if log.log_tier(ctx.options.verbosity) >= log.log_tier(e.level):
        #aggiunge un prefisso al messaggio
        ts = datetime.utcnow().isoformat("T", "seconds")
        level = "{:5s}".format(e.level.upper())
        e.msg = ts + " " + level + " " + e.msg
        #quello che c'era prima
        click.secho(
            e.msg,
            file=outfile,
            fg=dict(error="red", warn="yellow",
                    alert="magenta").get(e.level),
            dim=(e.level == "debug"),
            err=(e.level == "error")
        )

mhils · February 24, 2018, 10:44am

What kind of application do you have running at localhost:8000? With which requests does that happen? Every second one? It could be a keepalive issue.

Besides that, do you have steps to reproduce the UnicodeEncodeError present in your logs?

Gigiarum · February 26, 2018, 11:18am

This is my situation:
immagine

Usually client requests go to host requested but for a special domain I added a script to redirect to a own site hsoted on a Django in the same mitmproxy server. The site is very simple and loads first html page then standard resources as bootstrap, jquery, images, … When I try to load the main page I see many errors in browsers console with various resources (css, favicon, …). If I try to refresh the main page sometimes also the html returns with 502 error. I focused also on bootstrap css (direct single resource from the browser) and I get response sometimes good and sometimes mitmproxy errore above reported. Now I don’t have a link to the system but I remember the behaviour was like one time yes and one time no.

I try also to disable Django CSRF, remove Referer header in mitmproxy redirected request but same error was present.

With another client I access normally to the same Django hosted site.

I am using mitmproxy v3.0.1. Can I give you other informations?

Gigiarum · February 28, 2018, 2:03pm

I tried another way to serve the redirect site: I moved Django on another pc but the problem still persist.

I can also confirm that if I point a single resource by the browser one call goes ok and one call ko.

I put here another log of the two calls: I find UnicodeEncodeError in both case so I focus on connection log.
In the OK case I find “clientconnect”, “Set new server address” and “serverconnect” that in KO case there are not. I searched 60315 in previous log and it is present in a 2 minute before call well ended.

KO case

2018-02-28T13:32:07 DEBUG ::ffff:192.168.3.128:60315: request
 -> Request(GET portale.sea:80/static/user_portal/css/bootstrap.css)
2018-02-28T13:32:07 DEBUG redirect request Chiamata reindirizzata.
2018-02-28T13:32:07 ERROR Addon error: Traceback (most recent call last):
 File "/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/mitmproxy/addons/termlog.py", line 37, in log
   err=(e.level == "error")
 File "/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/click/termui.py", line 420, in secho
   return echo(style(text, **styles), file=file, nl=nl, err=err, color=color)```
 File "/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/click/utils.py", line 259, in echo
   file.write(message)
UnicodeEncodeError: 'ascii' codec can't encode character '\xe0' in position 51: ordinal not in range(128)

2018-02-28T13:32:07 192.168.3.128:60315: GET http://192.168.3.33:8000/static/user_portal/css/bootstrap.css
2018-02-28T13:32:07     Host: 192.168.3.33
2018-02-28T13:32:07     Proxy-Connection: keep-alive
2018-02-28T13:32:07     Cache-Control: max-age=0
2018-02-28T13:32:07     Upgrade-Insecure-Requests: 1
2018-02-28T13:32:07     User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 >(KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36
2018-02-28T13:32:07     Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
2018-02-28T13:32:07     Accept-Encoding: gzip, deflate
2018-02-28T13:32:07     Accept-Language: it-IT,it;q=0.9,en-US;q=0.8,en;q=0.7
2018-02-28T13:32:07     If-Modified-Since: Wed, 03 Dec 2014 10:12:47 GMT
2018-02-28T13:32:07  << Server disconnected
2018-02-28T13:32:07 DEBUG ::ffff:192.168.3.128:60315: serverdisconnect
 -> ('192.168.3.33', 8000)
2018-02-28T13:32:07 INFO  192.168.3.128:60315: clientdisconnect

OK case

2018-02-28T13:32:42 INFO  192.168.3.128:60501: clientconnect
2018-02-28T13:32:42 DEBUG ::ffff:192.168.3.128:60501: request
 -> Request(GET portale.sea:80/static/user_portal/css/bootstrap.css)
2018-02-28T13:32:42 DEBUG redirect request Chiamata reindirizzata.
2018-02-28T13:32:42 ERROR Addon error: Traceback (most recent call last):
 File "/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/mitmproxy/addons/termlog.py", line 37, in log
   err=(e.level == "error")
 File "/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/click/termui.py", line 420, in secho
   return echo(style(text, **styles), file=file, nl=nl, err=err, color=color)
 File "/root/.pyenv/versions/3.6.3/lib/python3.6/site-packages/click/utils.py", line 259, in echo
   file.write(message)
UnicodeEncodeError: 'ascii' codec can't encode character '\xe0' in position 51: ordinal not in range(128)

2018-02-28T13:32:42 DEBUG ::ffff:192.168.3.128:60501: Set new server address: 192.168.3.33:8000
2018-02-28T13:32:42 DEBUG ::ffff:192.168.3.128:60501: serverconnect
 -> ('192.168.3.33', 8000)
2018-02-28T13:32:42 DEBUG ::ffff:192.168.3.128:60501: response
 -> Response(200 OK, text/css, 132.77k)
2018-02-28T13:32:42 192.168.3.128:60501: GET http://192.168.3.33:8000/static/user_portal/css/bootstrap.css
2018-02-28T13:32:42     Host: 192.168.3.33
2018-02-28T13:32:42     Proxy-Connection: keep-alive
2018-02-28T13:32:42     Cache-Control: max-age=0
2018-02-28T13:32:42     Upgrade-Insecure-Requests: 1
2018-02-28T13:32:42     User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36
2018-02-28T13:32:42     Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
2018-02-28T13:32:42     Accept-Encoding: gzip, deflate
2018-02-28T13:32:42     Accept-Language: it-IT,it;q=0.9,en-US;q=0.8,en;q=0.7
2018-02-28T13:32:42  << 200 OK 132.77k
2018-02-28T13:32:42     Date: Wed, 28 Feb 2018 13:32:42 GMT
2018-02-28T13:32:42     Server: WSGIServer/0.2 CPython/3.6.3
2018-02-28T13:32:42     Content-Type: text/css
2018-02-28T13:32:42     Last-Modified: Wed, 03 Dec 2014 10:12:47 GMT
2018-02-28T13:32:42     Content-Length: 135954

script

from mitmproxy import ctx, http
from traceback import print_exc

def request(self, flow):
   try:
       if flow.request.pretty_host == "portale.sea":
           flow.request.host = "192.168.3.33"
           flow.request.port = 8000

           flow.metadata["my_redirect_flag"] = True
           ctx.log.debug("redirect request Chiamata reindirizzata.")
   except Exception as e:
       ctx.log.error("redirect request Eccezione.")
       print_exc(file=sys.stderr)
       flow.response = http.HTTPResponse.make(533, b"REDIRECT ERROR", { "Content-Type": "text/html" })

Gigiarum · March 8, 2018, 10:53am

I did other tests and the exception is a different problem (issue).

Server disconnection is not present if I use a simple http server instead of Django.
Further news in next days.

Gigiarum · April 5, 2018, 12:34pm

Same problem here.

mhils · April 5, 2018, 4:03pm

Hi, we just released mitmproxy 3.0.4 - I believe this should fix this issue!

Gigiarum · April 6, 2018, 12:44pm

It fixes, thank you!

Topic		Replies	Views
Intermittent 502 errors with version 3.0.3 help	8	3677	April 5, 2018
Errno 61 Connection refused help	9	9902	April 13, 2017
Issues with transparent mode help	2	3369	August 9, 2016
Errno 10061 - No connection could be made because the target machine actively refused it help	6	6139	January 30, 2017
Mitmproxy https connection failure help	3	1548	April 24, 2017

Server disconnected on redirect

These get over-ridden by the save execution context. Keep them around so we

can log directly.

Related Topics