Opened 5 years ago

Closed 2 years ago

#11090 closed defect (not a bug)

torsocks should log errors to stderr and not stdout

Reported by: infinity0 Owned by: dgoulet
Priority: Medium Milestone:
Component: Core Tor/Torsocks Version:
Severity: Normal Keywords:
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

torsocks 2.0.0-rc3

I get stuff like this on stdout:

[Feb 28 14:05:16] WARNING torsocks[22952]: Non TCP inet socket denied. Tor network can't handle it. (in tsocks_socket() at socket.c:40)

Logging to stdout interferes with the output of the underlying program, and is generally a bad idea.

Child Tickets

Change History (16)

comment:1 Changed 5 years ago by infinity0

Owner: changed from ioerror to dgoulet
Status: newassigned

comment:2 Changed 5 years ago by dgoulet

Hrm that's a bit weird because the default is to use stderr... If you look at src/common/log.c +166, a check is made on stderr if it exists and valid else it's going to use 0 (stdout).

Is there at some point anything that closes stderr in your use case that could prevent torsocks from using it?

comment:3 Changed 5 years ago by infinity0

My use case is parcimonie, I will ping the author:

$ aptitude show parcimonie torsocks | grep Version
Version: 0.8.1-1
Version: 2.0.0~rc3-1
$ parcimonie --verbose 2>/dev/null
[Mar 02 22:16:09] WARNING torsocks[9119]: Non TCP inet socket denied. Tor network can't handle it. (in tsocks_socket() at socket.c:40)
[Mar 02 22:16:09] WARNING torsocks[9119]: Non TCP inet socket denied. Tor network can't handle it. (in tsocks_socket() at socket.c:40)

comment:4 in reply to:  3 Changed 5 years ago by intrigeri

Owner: changed from dgoulet to intrigeri

Replying to infinity0:

My use case is parcimonie, I will ping the author:

I'm sorry, I still did not have time to look into this (nor to test torsocks 2.x at all, btw).
Pinging me about it every 2-4 weeks might help.

My plan is to try and reproduce it, and then extract a minimal test case (if I suspect the problem is in an underlying library) or fix my code (if the problem is there). I would certainly not mind any help, by the way. The thing is written in Modern Perl.

Reassigning to me as I'm the one who is committed to do the next action. Feel free to revert if this was not appropriate use of these crazy new things I can click on Trac :)

Last edited 5 years ago by intrigeri (previous) (diff)

comment:5 Changed 5 years ago by intrigeri

I can't reproduce that with parcimonie 0.8.3-1 and torsocks 2.0.0-1 (which I'll upload to Debian unstable right now). infinity0, is there anything specific in your setup that might trigger this?

comment:6 Changed 5 years ago by intrigeri

Status: assignedneeds_information

comment:7 Changed 4 years ago by dgoulet

Any update on that? I confirm that it's going on stderr.

comment:8 Changed 4 years ago by intrigeri

Owner: changed from intrigeri to infinity0
Status: needs_informationassigned

I've looked again at what parcimonie does when fetching keys, and was not able to find any place where it would itself output torsocks-related stuff to stdout. On GnuPG errors, parcimonie always sends captured output to stderr. So, infinity0: can you please provide instructions to reproduce this bug in a clean environment?

comment:9 Changed 4 years ago by infinity0

$ sudo sed -i -e 's/9050/9059/g' /etc/tor/torsocks.conf # force an error from torsocks

$ parcimonie --verbose 2>/dev/null
[Apr 23 11:08:39] PERROR torsocks[29673]: socks5 libc connect: Connection refused (in socks5_connect() at socks5.c:185)
gpgkeys: HTTP fetch error 6: Could not resolve host: pool.sks-keyservers.net

Using versions from Debian sid:

$ apt-cache policy torsocks
torsocks:
  Installed: 2.0.0-3
  Candidate: 2.0.0-3
  Version table:
 *** 2.0.0-3 0
        990 http://ftp.uk.debian.org/debian/ testing/main amd64 Packages
        500 http://ftp.uk.debian.org/debian/ unstable/main amd64 Packages
        100 /var/lib/dpkg/status
     1.3-3~precise 0
        500 http://ppa.launchpad.net/guardianproject/ppa/ubuntu/ precise/main amd64 Packages

$ apt-cache policy parcimonie 
parcimonie:
  Installed: 0.8.4-1
  Candidate: 0.8.4-1
  Version table:
 *** 0.8.4-1 0
        990 http://ftp.uk.debian.org/debian/ testing/main amd64 Packages
        500 http://ftp.uk.debian.org/debian/ unstable/main amd64 Packages
        100 /var/lib/dpkg/status
     0.7.1-1+deb7u1 0
        500 http://security.debian.org/ stable/updates/main amd64 Packages

comment:10 Changed 4 years ago by infinity0

Just pinging to ask if the "reproducing" steps I gave actually work for you guys, or whether it only works on my machine or if I am going crazy..

comment:11 in reply to:  10 Changed 4 years ago by intrigeri

Replying to infinity0:

Just pinging to ask if the "reproducing" steps I gave actually work for you guys, or whether it only works on my machine or if I am going crazy..

Yay, yay, I'll do that. Just so you know: generally, pinging me every two weeks is the sweet spot; pinging me 28 hours after sending the requested info is a little bit stressful. Take care :)

comment:12 Changed 4 years ago by intrigeri

Owner: changed from infinity0 to intrigeri

comment:13 Changed 4 years ago by intrigeri

Owner: changed from intrigeri to dgoulet

OK, I can reproduce that. Thanks!

On current Debian unstable, after breaking torsocks.conf like infinity0 did:

$ torsocks gpg --recv-keys A63BB098
gpg: requesting key A63BB098 from hkps server hkps.pool.sks-keyservers.net
[Apr 25 16:34:44] PERROR torsocks[1923]: socks5 libc connect: Connection refused (in socks5_connect() at socks5.c:185)
gpgkeys: HTTP fetch error 6: Could not resolve host: hkps.pool.sks-keyservers.net
gpg: no valid OpenPGP data found.
gpg: Total number processed: 0
toto@sid-desktop:~$ torsocks gpg --recv-keys A63BB098 2>/dev/null
[Apr 25 16:34:54] PERROR torsocks[1927]: socks5 libc connect: Connection refused (in socks5_connect() at socks5.c:185)
gpgkeys: HTTP fetch error 6: Could not resolve host: hkps.pool.sks-keyservers.net

and:

$ torsocks gpg --recv-keys A63BB098 2>/dev/null
[Apr 25 16:37:50] PERROR torsocks[2168]: socks5 libc connect: Connection refused (in socks5_connect() at socks5.c:185)
gpgkeys: HTTP fetch error 6: Could not resolve host: hkps.pool.sks-keyservers.net

So it looks like both torsocks and gpgkeys send some error output to stdout, and parcimonie isn't at fault here => reassigning to David.

comment:14 Changed 3 years ago by dgoulet

Severity: Normal
Status: assignedneeds_information

I can confirm that torsocks does write errors on stderr with the gpg test case in last comment:

16512 write16512 write(2, "[Jun 13 17:19:04] PERROR torsock"..., 120) = 120 (2, "[Jun 13 17:19:04] PERROR torsock"..., 120) = 120

So I think here the issue is a multi process one. In the strace I see that gpg calls:

16512 execve("/usr/lib/gnupg/gpgkeys_hkp", ["/usr/lib/gnupg/gpgkeys_hkp"], [/* 56 vars */] <unfinished ...>

... and for that process, 2>/dev/null seems to not being applied. That's possibly an issue with torsocks that is the redirection to devnull is not given to the gpg process (maybe?)...

comment:15 Changed 3 years ago by intrigeri

Testing without torsocks (/usr/bin/gpg --recv-keys AAAAAAAB, i.e. a keyid that's not on keyservers currently) suggests that torsocks does pass the redirection to gpg, but that one doesn't pass it to gpgkeys_hkp. So in the end, it might be a bug in gpg, and not in torsocks.

comment:16 Changed 2 years ago by dgoulet

Resolution: not a bug
Status: needs_informationclosed
Note: See TracTickets for help on using tickets.