Opened 6 years ago

Closed 6 years ago

Last modified 5 years ago

#10081 closed defect (fixed)

TBB 2.4 on OSX, SO_REUSEADDR errors

Reported by: sniper976 Owned by:
Priority: Medium Milestone: Tor: 0.2.5.x-final
Component: Core Tor/Tor Version: Tor: 0.2.4.17-rc
Severity: Keywords: tor-relay osx needs-investigation 024-backport 025-triaged
Cc: blahu77@… Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

In the message log for the OSX version of TBB 2.4, I see a lot of these entries:

Error setting SO_REUSEADDR flag: Invalid argument

This occurs in both the 32- and 64-bit versions. Next to zero activity in the bandwidth graph. No problems with 2.3 which shows a lot of activity in the bandwidth graph (20Mbps in both directions almost continually). Operating an exit node.

Problem existed in Mountain Lion. Problem remained after a format/install of Mavericks.

Child Tickets

Change History (18)

comment:1 Changed 6 years ago by sniper976

Milestone: Tor: 0.2.4.x-final

comment:2 Changed 6 years ago by arma

Component: Tor bundles/installationTor
Keywords: tor-relay added; error tbb removed
Priority: blockernormal

comment:3 Changed 6 years ago by arma

Owner: erinn deleted
Status: newassigned

comment:4 Changed 6 years ago by nickm

Let's think. If it's TBB, I assume it's client-only.

We only set SO_REUSEADDR on a listener socket, and only after opening it and checking that SOCKET_OK is true on that socket.

I just tried this on Mavericks and it doesn't fail for me. Do you have any firewall or AV software running, or anything that would affect the network code?

Are you able to build Tor from source? If so, does it have the same problem when you use a copy you built from source?

comment:5 in reply to:  4 Changed 6 years ago by sniper976

I am using TBB, but as an exit relay (with all exit policies checked). I do not get that error message on the rare occasion that I run it as client-only (although that could be because I haven't been running it for long enough), as client-only browsing is done on my Windows machine.

No firewall, no AV software. As I said before, I have no problems with anything from the 2.3 branch. It's just 2.4 that I'm having this problem with.

I'm unable to build Tor from source.

Last edited 6 years ago by sniper976 (previous) (diff)

comment:6 Changed 6 years ago by jeffodell

I just built and installed 0.2.40.20 on my Mac (Old PPC Mac Mini)

About 10 minutes after starting Tor, I start receiving the same errors in the system.log.

Error setting SO_REUSEASDDR flag: Invalid argument

I disabled the OSX firewall and restarted to verify that the firewall was not the cause of the problem. This error did not occur while running 0.2.3.25.

Let me know what information I can provide to help resolve this issue.

Jeff

comment:7 Changed 6 years ago by jlgtx

I'm seeing the same errors, two in a row roughly every 30 minutes or so, sometimes more frequently. Running Tor 0.2.4.20, compiled from source, on Mac OS X 10.6.8 Server. Used --enable-static-openssl with OpenSSL 1.0.1f, also compiled from source, so I could enable-ec_nistp_64_gcc_128.

Version 0, edited 6 years ago by jlgtx (next)

comment:8 Changed 6 years ago by siekiera

same here on 10.7.5 with brewed tor:

Tor v0.2.4.20 (git-3cb5c70beec5bf46) running on Darwin with Libevent 2.0.21-stable and OpenSSL 1.0.1f

Would running the debug log help?

comment:9 Changed 6 years ago by siekiera

Cc: blahu77@… added

comment:10 Changed 6 years ago by nickm

Keywords: needs-investigation 024-backport added
Milestone: Tor: 0.2.4.x-finalTor: 0.2.5.x-final

comment:11 Changed 6 years ago by nickm

Keywords: 025-triaged added

I half-suspect this is happening in the case where we have just accepted a socket, and the other side has shut down the socket right after we accepted it.

From the manpage

     The getsockopt() and setsockopt() system calls will succeed unless:
...
     [EINVAL]           The option is invalid at the level indicated.

     The setsockopt() system call will succeed unless:
...
     [EINVAL]           The socket has been shut down.

comment:12 Changed 6 years ago by nickm

Status: assignedneeds_review

I have a theory that my branch "bug10081" will behave better here. It clarifies whether the warning is occurring on a socket that we're using to listen, to accept(), or to connect(). In the accept() case, it doesn't warn about EINVAL, since the OSX manpage suggests we'll encounter those sometimes.

Doing an 0.2.4 backport will take a modicum of work, since there is a conflict in cherry-picking this back.

comment:13 in reply to:  12 Changed 6 years ago by andrea

Replying to nickm:

I have a theory that my branch "bug10081" will behave better here. It clarifies whether the warning is occurring on a socket that we're using to listen, to accept(), or to connect(). In the accept() case, it doesn't warn about EINVAL, since the OSX manpage suggests we'll encounter those sometimes.

Doing an 0.2.4 backport will take a modicum of work, since there is a conflict in cherry-picking this back.

I think your bug10081 branch looks okay to me.

comment:14 Changed 6 years ago by nickm

Milestone: Tor: 0.2.5.x-finalTor: 0.2.4.x-final

cool; merged! Moving to 0.2.4 for possible backport.

comment:15 Changed 6 years ago by nickm

recommendation: no backport; merely annoying.

comment:16 Changed 6 years ago by arma

"no backport" is fine with me.

It would be neat to get one of the reporters here to try Tor 0.2.5.x (now that it has your patch) and tell us whether the messages go away for them.

comment:17 Changed 6 years ago by nickm

Milestone: Tor: 0.2.4.x-finalTor: 0.2.5.x-final
Resolution: fixed
Status: needs_reviewclosed

Okay, no backport to 0.2.4 for these, for stability reasons.

comment:18 Changed 5 years ago by siekiera

Tor v0.2.5.4-alpha (git-d2147cc7ba5c5d51) running on Darwin with Libevent 2.0.21-stable, OpenSSL 1.0.1g and Zlib 1.2.5.

messages did go away. Success!

Now I see another: "Unexpected sendme cell from client. Closing circ (window 1000)."
any idea what it is?

Here's the system.log for last 2 days:

May 31 03:14:40 localhost Tor[98130]: Heartbeat: Tor's uptime is 4 days 6:00 hours, with 208 circuits open. I've sent 49.89 GB and received 47.03 GB.
May 31 03:14:40 localhost Tor[98130]: Average packaged cell fullness: 98.904%
May 31 03:14:40 localhost Tor[98130]: TLS write overhead: 4%
May 31 03:14:40 localhost Tor[98130]: Circuit handshake stats since last time: 19042/19042 TAP, 1900/1900 NTor.
May 31 08:04:22 localhost Tor[98130]: Unexpected sendme cell from client. Closing circ (window 1000).
May 31 08:52:11 localhost Tor[98130]: Unexpected sendme cell from client. Closing circ (window 1000).
May 31 09:14:40 localhost Tor[98130]: Heartbeat: Tor's uptime is 4 days 12:00 hours, with 260 circuits open. I've sent 53.42 GB and received 50.43 GB.
May 31 09:14:40 localhost Tor[98130]: Average packaged cell fullness: 98.903%
May 31 09:14:40 localhost Tor[98130]: TLS write overhead: 4%
May 31 09:14:40 localhost Tor[98130]: Circuit handshake stats since last time: 19890/19890 TAP, 1831/1831 NTor.
May 31 09:22:55 localhost Tor[98130]: Unexpected sendme cell from client. Closing circ (window 1000).
May 31 09:40:17 localhost Tor[98130]: Unexpected sendme cell from client. Closing circ (window 1000).
May 31 09:56:53 localhost Tor[98130]: Unexpected sendme cell from client. Closing circ (window 1000).
May 31 10:09:19 localhost Tor[98130]: Unexpected sendme cell from client. Closing circ (window 1000). [1 similar message(s) suppressed in last 600 seconds]
May 31 10:22:35 localhost Tor[98130]: Unexpected sendme cell from client. Closing circ (window 1000). [2 similar message(s) suppressed in last 600 seconds]
May 31 15:14:40 localhost Tor[98130]: Heartbeat: Tor's uptime is 4 days 18:00 hours, with 355 circuits open. I've sent 56.20 GB and received 53.06 GB.
May 31 15:14:40 localhost Tor[98130]: Average packaged cell fullness: 98.901%
May 31 15:14:40 localhost Tor[98130]: TLS write overhead: 4%
May 31 15:14:40 localhost Tor[98130]: Circuit handshake stats since last time: 25566/25566 TAP, 2065/2065 NTor.
May 31 21:14:40 localhost Tor[98130]: Heartbeat: Tor's uptime is 5 days 0:00 hours, with 527 circuits open. I've sent 59.56 GB and received 56.18 GB.
May 31 21:14:40 localhost Tor[98130]: Average packaged cell fullness: 98.889%
May 31 21:14:40 localhost Tor[98130]: TLS write overhead: 4%
May 31 21:14:40 localhost Tor[98130]: Circuit handshake stats since last time: 46186/46186 TAP, 4681/4681 NTor.
Jun 1 03:14:40 localhost Tor[98130]: Heartbeat: Tor's uptime is 5 days 6:00 hours, with 374 circuits open. I've sent 64.94 GB and received 61.32 GB.
Jun 1 03:14:40 localhost Tor[98130]: Average packaged cell fullness: 98.864%
Jun 1 03:14:40 localhost Tor[98130]: TLS write overhead: 4%
Jun 1 03:14:40 localhost Tor[98130]: Circuit handshake stats since last time: 35736/35736 TAP, 4774/4774 NTor.
Jun 1 09:14:40 localhost Tor[98130]: Heartbeat: Tor's uptime is 5 days 12:00 hours, with 472 circuits open. I've sent 68.89 GB and received 65.07 GB.
Jun 1 09:14:40 localhost Tor[98130]: Average packaged cell fullness: 98.845%
Jun 1 09:14:40 localhost Tor[98130]: TLS write overhead: 4%
Jun 1 09:14:40 localhost Tor[98130]: Circuit handshake stats since last time: 30526/30526 TAP, 3855/3855 NTor.
Jun 1 09:24:24 localhost Tor[98130]: Unexpected sendme cell from client. Closing circ (window 1000).
Jun 1 10:05:54 localhost Tor[98130]: Unexpected sendme cell from client. Closing circ (window 1000).
Jun 1 15:14:40 localhost Tor[98130]: Heartbeat: Tor's uptime is 5 days 18:00 hours, with 518 circuits open. I've sent 71.95 GB and received 67.92 GB.
Jun 1 15:14:40 localhost Tor[98130]: Average packaged cell fullness: 98.829%
Jun 1 15:14:40 localhost Tor[98130]: TLS write overhead: 4%
Jun 1 15:14:40 localhost Tor[98130]: Circuit handshake stats since last time: 33973/33973 TAP, 3675/3675 NTor.

Note: See TracTickets for help on using tickets.