[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]
tor eating CPU time
- To: Tor Talk List <or-talk@xxxxxxxx>
- Subject: tor eating CPU time
- From: Valient Gough <vgough@xxxxxxxxx>
- Date: Fri, 28 Jan 2005 12:56:12 +0100
- Delivered-to: archiver@seul.org
- Delivered-to: or-talk-outgoing@seul.org
- Delivered-to: or-talk@seul.org
- Delivery-date: Fri, 28 Jan 2005 06:57:05 -0500
- Reply-to: or-talk@xxxxxxxxxxxxx
- Sender: owner-or-talk@xxxxxxxxxxxxx
- User-agent: Mozilla Thunderbird 1.0 (X11/20041207)
I upgraded to 0.0.9.3 last weekend, and it dropped tor's average CPU
usage by almost half.
However thing have been slowly getting worse. Saturday stats show about
30% CPU average usage, increasing slowly to a little over 40% on Wed,
then about 50% by Thursday, and about 12 hours ago tor jumped to 100%
cpu usage and has not taken a rest since then.
The strange thing is that this doesn't correlate with traffic served.
Tor traffic has been steadily averaging about 200k/sec, and started
dropping about 12 hours ago by as much as a factor of 2 (much higher
variation though). So, CPU time increased, but network traffic decreased...
Looking through my server monitoring logs, I don't see any correlation
against network usage or number of open TCP connections. I'm about to
restart TOR, but before I get into the habbit of periodic restarts, is
there anything I can do to get information about the problem?
In case it helps, here are the messages from warnings.log from about the
time when the CPU usage first pegged at 100% (the cpu pegged at about
15:50 server local time +- 10 minutes):
Jan 27 12:56:04.178 [warn] Bug: Double mark-for-close on connection.
Jan 27 12:56:04.178 [warn] Duplicate call to connection_mark_for_close
at relay.
c:567 (first at connection.c:861)
Jan 27 15:08:30.397 [warn] parse_addr_port(): Port ':80' out of range
Jan 27 15:08:30.397 [warn] connection_exit_begin_conn(): Unable to parse
addr:po
rt in relay begin cell. Dropping.
Jan 27 15:40:59.192 [warn] Bug: Double mark-for-close on connection.
Jan 27 15:40:59.193 [warn] Duplicate call to connection_mark_for_close
at relay.
c:567 (first at connection.c:861)
Jan 27 17:08:14.508 [warn] rend_mid_rendezvous(): Rejecting RENDEZVOUS1
cell wit
h unrecognized rendezvous cookie A2C5DA1B
Jan 27 17:35:31.927 [warn] onion_skin_server_handshake(): Couldn't
decrypt onion
skin: client may be using old onion key
Jan 27 17:35:31.928 [warn] cpuworker_main(): onion_skin_server_handshake
failed.
Jan 27 17:35:31.930 [warn] connection_cpu_process_inbuf(): decoding
onionskin fa
iled. Closing.
Jan 27 17:36:40.743 [warn] onion_skin_server_handshake(): Couldn't
decrypt onion
skin: client may be using old onion key
Jan 27 17:36:40.743 [warn] cpuworker_main(): onion_skin_server_handshake
failed.
Jan 27 17:36:40.746 [warn] connection_cpu_process_inbuf(): decoding
onionskin fa
iled. Closing.
Jan 27 17:37:27.594 [warn] onion_skin_server_handshake(): Couldn't
decrypt onion
skin: client may be using old onion key
Jan 27 17:37:27.594 [warn] cpuworker_main(): onion_skin_server_handshake
failed.
Jan 27 17:37:27.596 [warn] connection_cpu_process_inbuf(): decoding
onionskin fa
iled. Closing.
I only see 10 log messages for the last 4 hours, but CPU is 100%, so it
isn't in a busy loop logging messages.
Here are the messages tagged with 'Bug':
> grep Bug tor/warnings.log | cut -c 20- | sort | uniq -c
4 [warn] Bug: Double mark-for-close on connection.
10 [warn] connection_about_to_close_connection(): Bug: Edge
connection hasn't sent end yet?
268 [warn] connection_edge_end(): Bug: Calling connection_edge_end
on an already ended stream?
3 [warn] connection_or_connect(): Bug: Request to connect to
myself! Failing.
any ideas?
Valient