#24857: tor 0.3.1.9 100% cpu load --------------------------+----------------------------------- Reporter: Eugene646 | Owner: (none) Type: defect | Status: needs_information Priority: Medium | Milestone: Component: Core Tor/Tor | Version: Tor: 0.3.1.9 Severity: Normal | Resolution: Keywords: cpu, windows | Actual Points: Parent ID: | Points: Reviewer: | Sponsor: --------------------------+-----------------------------------
Comment (by creideiki): I restarted the Tor service and watched it closely. The error message "Failing because we have 4063 connections already" appears at the same time as it starts using 100% CPU. This time it took 6 minutes. At 3 minutes after starting the service, well after the log says the relay is up and running, "perf top" looks nice and sane like this: {{{ 16.76% tor [.] curve25519_donna 3.18% libcrypto.so.1.0.0 [.] __bn_sqrx8x_reduction 1.93% libcrypto.so.1.0.0 [.] mulx4x_internal 1.79% libcrypto.so.1.0.0 [.] bn_sqrx8x_internal 1.62% tor [.] connection_bucket_refill 1.58% tor [.] tor_memcmp 1.40% libc-2.26.so [.] _int_malloc 1.37% libc-2.26.so [.] malloc 1.29% libcrypto.so.1.0.0 [.] sha256_block_data_order_avx2 0.99% libc-2.26.so [.] __memmove_avx_unaligned_erms 0.96% libc-2.26.so [.] _int_free 0.93% tor [.] tor_memeq 0.73% tor [.] buf_datalen 0.73% [kernel] [k] ___bpf_prog_run 0.71% [kernel] [k] syscall_return_via_sysret 0.61% libcrypto.so.1.0.0 [.] __ecp_nistz256_mul_montx 0.57% [kernel] [k] __fget 0.55% libcrypto.so.1.0.0 [.] __ecp_nistz256_sqr_montx 0.53% libcrypto.so.1.0.0 [.] sha1_block_data_order_avx2 0.52% tor [.] channel_update_bad_for_new_circs 0.46% libssl.so.1.0.0 [.] ssl_cipher_apply_rule.isra.1 0.45% libpthread-2.26.so [.] __pthread_mutex_lock 0.43% libc-2.26.so [.] cfree@GLIBC_2.2.5 0.42% libcrypto.so.1.0.0 [.] _aesni_ctr32_ghash_6x }}} After 6 minutes, when the error message has appeared in the log and the process uses 100% CPU, "perf top" looks like this: {{{ 9.45% [kernel] [k] syscall_return_via_sysret 6.33% [unknown] [k] 0xfffffe00000b601e 5.16% [kernel] [k] ep_send_events_proc 3.48% [kernel] [k] ___bpf_prog_run 3.38% [kernel] [k] _raw_spin_lock_irqsave 3.19% [kernel] [k] read_tsc 3.06% [kernel] [k] __fget 2.75% libpthread-2.26.so [.] __pthread_mutex_lock 2.55% [kernel] [k] _raw_spin_unlock_irqrestore 2.49% [kernel] [k] seccomp_run_filters 2.33% libc-2.26.so [.] epoll_pwait 2.27% [kernel] [k] select_estimate_accuracy 2.25% libpthread-2.26.so [.] __pthread_mutex_unlock_usercnt 1.84% [kernel] [k] syscall_trace_enter 1.81% [kernel] [k] __seccomp_filter 1.78% libevent-2.1.so.6.0.2 [.] event_base_loop 1.65% [kernel] [k] ep_scan_ready_list.constprop.15 1.57% [unknown] [k] 0xfffffe000000601e 1.52% [kernel] [k] ep_poll 1.41% [kernel] [k] ktime_get_ts64 1.36% [kernel] [k] entry_SYSCALL_64_after_hwframe 1.35% libevent-2.1.so.6.0.2 [.] event_callback_activate_nolock_ 1.29% [unknown] [k] 0xfffffe00000b6000 1.10% tor [.] assert_connection_ok }}} And says the Tor process is spending 65% of its time in the kernel. Probably with those 69k/s epoll_pwait() calls. Network statistics says it's still shuffling its 10Mb/s, though, so it's doing something productive as well. Final Tor log is not very interesting, but for completeness: {{{ Jan 24 10:49:47.000 [notice] Tor 0.3.2.9 (git-9e8b762fcecfece6) opening log file. Jan 24 10:49:47.000 [notice] Parsing GEOIP IPv4 file /usr/share/tor/geoip. Jan 24 10:49:48.000 [notice] Parsing GEOIP IPv6 file /usr/share/tor/geoip6. Jan 24 10:49:48.000 [notice] Configured to measure statistics. Look for the *-stats files that will first be written to the data directory in 24 hours from now. Jan 24 10:49:48.000 [notice] Your Tor server's identity key fingerprint is CENSORED Jan 24 10:49:48.000 [notice] Bootstrapped 0%: Starting Jan 24 10:49:54.000 [notice] Starting with guard context "default" Jan 24 10:49:54.000 [notice] Bootstrapped 80%: Connecting to the Tor network Jan 24 10:49:54.000 [notice] Self-testing indicates your ORPort is reachable from the outside. Excellent. Jan 24 10:49:54.000 [notice] Bootstrapped 85%: Finishing handshake with first hop Jan 24 10:49:55.000 [notice] Bootstrapped 90%: Establishing a Tor circuit Jan 24 10:49:56.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working. Jan 24 10:49:56.000 [notice] Bootstrapped 100%: Done Jan 24 10:49:58.000 [notice] Self-testing indicates your DirPort is reachable from the outside. Excellent. Publishing server descriptor. Jan 24 10:50:00.000 [notice] Performing bandwidth self-test...done. Jan 24 10:56:04.000 [warn] Failing because we have 4063 connections already. Please read doc/TUNING for guidance. }}} -- Ticket URL: <https://trac.torproject.org/projects/tor/ticket/24857#comment:5> Tor Bug Tracker & Wiki <https://trac.torproject.org/> The Tor Project: anonymity online
_______________________________________________ tor-bugs mailing list tor-bugs@lists.torproject.org https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs