torproject / stem

Python controller library for Tor
https://stem.torproject.org/
GNU Lesser General Public License v3.0
257 stars 75 forks source link

noisy log: [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file" #112

Open milahu opened 2 years ago

milahu commented 2 years ago

logging is too noisy, debug/trace messages are printed as info messages

import time
import logging
import stem
import stem.control

tor_control_password = "..."
tor_control_port = 1234

logger = logging.getLogger('main')

with stem.control.Controller.from_port(port=tor_control_port) as tor:
  logger.info("authenticate")
  tor.authenticate(password=tor_control_password)
  logger.info("signal")
  tor.signal(stem.Signal.NEWNYM)
  while not tor.is_newnym_available():
    logger.info("sleep")
    time.sleep(tor.get_newnym_wait())
logger.info("done")

will produce this noisy log

2021-12-12 16:20:12 [main] INFO: authenticate
2021-12-12 16:20:12 [stem] DEBUG: GETCONF __owningcontrollerprocess (runtime: 0.0003)
2021-12-12 16:20:12 [main] INFO: signal
2021-12-12 16:20:12 [main] INFO: sleep
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "read of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [stem] INFO: Error while receiving a control message (SocketClosed): received exception "peek of closed file"
2021-12-12 16:20:22 [main] INFO: done

currently, this shows 19 times the Error while receiving a control message → show only once?

currently, this is using loglevel info → use loglevel debug/trace?

currently, DEBUG: GETCONF is visible by default → hide debug messages by default? (maybe somewhere in my env, i set loglevel to debug, not sure)

workaround: disable logging from stem

import stem.util
stem.util.log.get_logger().propagate = False # disable logging

im starting tor with

import subprocess
import shutil

args = [shutil.which("tor")]
args += ["--SocksPort", "auto"]
args += ["--ControlPort", "auto"]
args += ["--CookieAuthentication", "1"]
args += ["--Log", f"notice file {tor_log_file}"]
args += ["--Log", "notice stdout"]
args += ["--DataDirectory", tor_data_dir]

tor_process = subprocess.Popen(
  args,
  stdout=subprocess.PIPE,
  stderr=subprocess.PIPE,
  close_fds=True,
)

related

fschn90 commented 1 year ago

have you found anything somewhere else possibly? best flo