Opened 8 years ago

Closed 8 years ago

#5079 closed defect (fixed)

obfsproxy: scrub IPs before displaying them in logs

Reported by: asn Owned by: asn
Priority: Medium Milestone:
Component: Archived/Obfsproxy Version:
Severity: Keywords:
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

obfsproxy needs a SafeLogging option, with True as its default value.

Child Tickets

Attachments (1)

0001-bug5079-Scrub-IPs-before-displaying-them-in-logs.patch (18.3 KB) - added by cjbprime 8 years ago.

Download all attachments as: .zip

Change History (5)

comment:1 Changed 8 years ago by cjbprime

The attached patch implements this feature. I'm pasting the output of two runs below, one with scrubbing on and one with scrubbing off via "--no-safe-logging".

The scrubbing implemented here goes farther than Tor, in that it scrubs the client addresses too, to avoid putting live obfsproxy bridge addresses in the log. As a side effect, protocol traffic between obfsproxy and Tor is no longer logged. Safe logging is turned on by default, in main.c.

With scrubbing turned on:

2012-02-12 15:11:46 [info] Starting.
2012-02-12 15:11:46 [debug] Proxy environment:
state_loc: './Data/Tor/pt_state/'
conf_proto_version: '1'
transports: 'obfs2'
2012-02-12 15:11:46 [debug] Now listening on 127.0.0.1:0 for protocol obfs2.
2012-02-12 15:12:07 [debug] [scrubbed]: new connection from [scrubbed] (1 total)
2012-02-12 15:12:07 [debug] [scrubbed]: socks client connection
2012-02-12 15:12:07 [debug] [scrubbed]: setup complete
2012-02-12 15:12:07 [debug] [scrubbed]: socks_read_cb
2012-02-12 15:12:07 [debug] Got version 4
2012-02-12 15:12:07 [info] [scrubbed]: socks: trying to connect to [scrubbed]:80
2012-02-12 15:12:07 [debug] [scrubbed]: new connection from [scrubbed] (3 total)
2012-02-12 15:12:07 [debug] [scrubbed]: socks client connection
2012-02-12 15:12:07 [debug] [scrubbed]: setup complete
2012-02-12 15:12:07 [debug] [scrubbed]: socks_read_cb
2012-02-12 15:12:07 [debug] Got version 4
2012-02-12 15:12:07 [info] [scrubbed]: socks: trying to connect to [scrubbed]:80
2012-02-12 15:12:07 [debug] [scrubbed]: pending_socks_cb
2012-02-12 15:12:07 [debug] We connected to our SOCKS destination! Replacing peername '[scrubbed]' with '[scrubbed]'
2012-02-12 15:12:07 [debug] [scrubbed]: Successful outbound connection to [scrubbed]
2012-02-12 15:12:07 [debug] obfs2_handshake: initiator queued 7033 bytes
2012-02-12 15:12:07 [debug] [scrubbed]: upstream_read_cb, 336 bytes available
2012-02-12 15:12:07 [debug] obfs2_send: handshake incomplete, queueing 336 bytes.
2012-02-12 15:12:07 [debug] [scrubbed]: transmitted 0 bytes
2012-02-12 15:12:07 [debug] [scrubbed]: pending_socks_cb
2012-02-12 15:12:07 [debug] We connected to our SOCKS destination! Replacing peername '[scrubbed]' with '[scrubbed]'
2012-02-12 15:12:07 [debug] [scrubbed]: Successful outbound connection to [scrubbed]
2012-02-12 15:12:07 [debug] obfs2_handshake: initiator queued 3240 bytes
2012-02-12 15:12:07 [debug] [scrubbed]: downstream_read_cb, 1448 bytes available
2012-02-12 15:12:07 [debug] [scrubbed]: error during receive.
2012-02-12 15:12:07 [debug] Closing connection with [scrubbed]; 3 remaining
2012-02-12 15:12:07 [debug] Closing connection with [scrubbed]; 2 remaining
2012-02-12 15:12:07 [debug] [scrubbed]: downstream_read_cb, 808 bytes available
2012-02-12 15:12:07 [debug] [scrubbed]: error during receive.
2012-02-12 15:12:07 [debug] Closing connection with [scrubbed]; 1 remaining
2012-02-12 15:12:07 [debug] Closing connection with [scrubbed]; 0 remaining
2012-02-12 15:12:08 [debug] [scrubbed]: new connection from [scrubbed] (1 total)
2012-02-12 15:12:08 [debug] [scrubbed]: socks client connection
2012-02-12 15:12:08 [debug] [scrubbed]: setup complete
2012-02-12 15:12:08 [debug] [scrubbed]: socks_read_cb
2012-02-12 15:12:08 [debug] Got version 4
2012-02-12 15:12:08 [info] [scrubbed]: socks: trying to connect to [scrubbed]:80
2012-02-12 15:12:08 [debug] [scrubbed]: new connection from [scrubbed] (3 total)
2012-02-12 15:12:08 [debug] [scrubbed]: socks client connection
2012-02-12 15:12:08 [debug] [scrubbed]: setup complete
2012-02-12 15:12:08 [debug] [scrubbed]: socks_read_cb
2012-02-12 15:12:08 [debug] Got version 4
2012-02-12 15:12:08 [info] [scrubbed]: socks: trying to connect to [scrubbed]:80
2012-02-12 15:12:08 [debug] [scrubbed]: pending_socks_cb
2012-02-12 15:12:08 [debug] We connected to our SOCKS destination! Replacing peername '[scrubbed]' with '[scrubbed]'
2012-02-12 15:12:08 [debug] [scrubbed]: Successful outbound connection to [scrubbed]
2012-02-12 15:12:08 [debug] obfs2_handshake: initiator queued 580 bytes
2012-02-12 15:12:08 [debug] [scrubbed]: upstream_read_cb, 340 bytes available
2012-02-12 15:12:08 [debug] obfs2_send: handshake incomplete, queueing 340 bytes.
2012-02-12 15:12:08 [debug] [scrubbed]: transmitted 0 bytes
2012-02-12 15:12:08 [debug] [scrubbed]: pending_socks_cb
2012-02-12 15:12:08 [debug] We connected to our SOCKS destination! Replacing peername '[scrubbed]' with '[scrubbed]'
2012-02-12 15:12:08 [debug] [scrubbed]: Successful outbound connection to [scrubbed]
2012-02-12 15:12:08 [debug] obfs2_handshake: initiator queued 2568 bytes
2012-02-12 15:12:08 [debug] [scrubbed]: downstream_read_cb, 1448 bytes available
2012-02-12 15:12:08 [debug] [scrubbed]: error during receive.
2012-02-12 15:12:08 [debug] Closing connection with [scrubbed]; 3 remaining
2012-02-12 15:12:08 [debug] Closing connection with [scrubbed]; 2 remaining
2012-02-12 15:12:28 [debug] [scrubbed]: downstream_read_cb, 593 bytes available
2012-02-12 15:12:28 [debug] [scrubbed]: error during receive.
2012-02-12 15:12:28 [debug] Closing connection with [scrubbed]; 1 remaining
2012-02-12 15:12:28 [debug] Closing connection with [scrubbed]; 0 remaining

And with scrubbing off:

2012-02-12 15:16:01 [info] Starting.
2012-02-12 15:16:01 [debug] Proxy environment:
state_loc: './Data/Tor/pt_state/'
conf_proto_version: '1'
transports: 'obfs2'
2012-02-12 15:16:01 [debug] We sent:
2012-02-12 15:16:01 [debug] VERSION 1

2012-02-12 15:16:01 [debug] Now listening on 127.0.0.1:0 for protocol obfs2.
2012-02-12 15:16:01 [debug] We sent:
2012-02-12 15:16:01 [debug] CMETHOD obfs2 socks5 127.0.0.1:32998

2012-02-12 15:16:01 [debug] We sent:
2012-02-12 15:16:01 [debug] CMETHODS DONE

2012-02-12 15:16:35 [debug] 127.0.0.1:0: new connection from 127.0.0.1:53439 (1 total)
2012-02-12 15:16:35 [debug] 127.0.0.1:53439: socks client connection
2012-02-12 15:16:35 [debug] 127.0.0.1:53439: setup complete
2012-02-12 15:16:35 [debug] 127.0.0.1:0: new connection from 127.0.0.1:53440 (2 total)
2012-02-12 15:16:35 [debug] 127.0.0.1:53440: socks client connection
2012-02-12 15:16:35 [debug] 127.0.0.1:53440: setup complete
2012-02-12 15:16:35 [debug] 127.0.0.1:53439: socks_read_cb
2012-02-12 15:16:35 [debug] Got version 4
2012-02-12 15:16:35 [info] 127.0.0.1:53439: socks: trying to connect to 89.145.121.20:80
2012-02-12 15:16:35 [debug] 127.0.0.1:53440: socks_read_cb
2012-02-12 15:16:35 [debug] Got version 4
2012-02-12 15:16:35 [info] 127.0.0.1:53440: socks: trying to connect to 89.145.121.20:80
2012-02-12 15:16:35 [debug] 89.145.121.20:80: pending_socks_cb
2012-02-12 15:16:35 [debug] We connected to our SOCKS destination! Replacing peername '89.145.121.20:80' with '89.145.121.20:80'
2012-02-12 15:16:35 [debug] 127.0.0.1:53439: Successful outbound connection to 89.145.121.20:80
2012-02-12 15:16:35 [debug] obfs2_handshake: initiator queued 1347 bytes
2012-02-12 15:16:35 [debug] 127.0.0.1:53439: upstream_read_cb, 376 bytes available
2012-02-12 15:16:35 [debug] obfs2_send: handshake incomplete, queueing 376 bytes.
2012-02-12 15:16:35 [debug] 89.145.121.20:80: transmitted 0 bytes
2012-02-12 15:16:35 [debug] 89.145.121.20:80: pending_socks_cb
2012-02-12 15:16:35 [debug] We connected to our SOCKS destination! Replacing peername '89.145.121.20:80' with '89.145.121.20:80'
2012-02-12 15:16:35 [debug] 127.0.0.1:53440: Successful outbound connection to 89.145.121.20:80
2012-02-12 15:16:35 [debug] obfs2_handshake: initiator queued 3355 bytes
2012-02-12 15:16:35 [debug] 89.145.121.20:80: downstream_read_cb, 306 bytes available
2012-02-12 15:16:35 [debug] 89.145.121.20:80: error during receive.
2012-02-12 15:16:35 [debug] Closing connection with 127.0.0.1:53440; 3 remaining
2012-02-12 15:16:35 [debug] Closing connection with 89.145.121.20:80; 2 remaining

comment:2 Changed 8 years ago by asn

Status: newneeds_review

Thanks for the patch cjb!

Marking this as needs_review.

comment:3 Changed 8 years ago by nickm

Looks good, except for the function name. By the Tor convention, I think this should just be "safe_str": obfsproxy doesn't have a separate notion of "my activities as a client" and "my activities as a server.

This is pretty easy to fix with perl, though. I'll tweak the patch and merge it. Thanks!

comment:4 Changed 8 years ago by nickm

Resolution: fixed
Status: needs_reviewclosed
Note: See TracTickets for help on using tickets.