Opened 13 months ago

Closed 8 months ago

#20451 closed defect (fixed)

The communication stream of managed proxy '/usr/bin/meek-client' is 'closed'

Reported by: tagener-noisu Owned by: dcf
Priority: Medium Milestone:
Component: Obfuscation/meek Version:
Severity: Normal Keywords:
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

Tested on archlinux, using this package https://aur.archlinux.org/packages/meek/. PKGBUILD seems ok, meek-client is working (tested with meek-client --help)
torrc file:

Log notice syslog
DataDirectory /var/lib/tor
UseBridges 1
ClientTransportPlugin meek exec /usr/bin/meek-client --log meek-client.log
Bridge meek 0.0.2.0:3 url=https://az668014.vo.msecnd.net/ front=ajax.aspnetcdn.com
Bridge meek 0.0.2.0:2 url=https://d2zfqthxsdq309.cloudfront.net/ front=a0.awsstatic.com

Tor service status:

● tor.service - Anonymizing Overlay Network
   Loaded: loaded (/usr/lib/systemd/system/tor.service; disabled; vendor preset: disabled)
   Active: inactive (dead)

Oct 25 05:20:07 laptop Tor[26070]: Delaying directory fetches: No running bridges
Oct 25 05:20:08 laptop Tor[26070]: The communication stream of managed proxy '/usr/bin/meek-client' is 'closed'. Most probably the managed proxy stopped running. This might be a bug of the managed proxy, a bug of Tor, or a misconfiguration. Please enable logging on your managed proxy and check the logs for errors.
Oct 25 05:20:09 laptop Tor[26070]: Bootstrapped 5%: Connecting to directory server
Oct 25 05:20:09 laptop Tor[26070]: We were supposed to connect to bridge '0.0.2.0:3' using pluggable transport 'meek', but we can't find a pluggable transport proxy supporting 'meek'. This can happen if you haven't provided a ClientTransportPlugin line, or if your pluggable transport proxy stopped running.
Oct 25 05:20:09 laptop Tor[26070]: Problem bootstrapping. Stuck at 5%: Connecting to directory server. (Can't connect to bridge; PT_MISSING; count 1; recommendation warn; host 0000000000000000000000000000000000000000 at 0.0.2.0:3)
Oct 25 05:20:09 laptop Tor[26070]: We were supposed to connect to bridge '0.0.2.0:2' using pluggable transport 'meek', but we can't find a pluggable transport proxy supporting 'meek'. This can happen if you haven't provided a ClientTransportPlugin line, or if your pluggable transport proxy stopped running.
Oct 25 05:20:09 laptop Tor[26070]: Problem bootstrapping. Stuck at 5%: Connecting to directory server. (Can't connect to bridge; PT_MISSING; count 2; recommendation warn; host 0000000000000000000000000000000000000000 at 0.0.2.0:2)
Oct 25 05:21:31 laptop systemd[1]: Stopping Anonymizing Overlay Network...
Oct 25 05:21:31 laptop Tor[26070]: Interrupt: exiting cleanly.
Oct 25 05:21:31 laptop systemd[1]: Stopped Anonymizing Overlay Network.

Meek doesn't create any log files.

Child Tickets

Attachments (1)

0001-Emit-a-CMETHOD-ERROR-or-SMETHOD-ERROR-when-failing-t.patch (2.8 KB) - added by dcf 8 months ago.

Download all attachments as: .zip

Change History (13)

comment:1 Changed 13 months ago by yawning

Why are you using that anyway? From the PKGBUILD it's running helper-less so it's going to be blatantly obvious that it's a meek client.

comment:2 in reply to:  1 Changed 13 months ago by tagener-noisu

Replying to yawning:

Why are you using that anyway? From the PKGBUILD it's running helper-less so it's going to be blatantly obvious that it's a meek client.

Using what?

comment:3 Changed 13 months ago by dcf

You might have to report this bug to the maintainer of the AUR package.

What do you get when you run this command?

TOR_PT_MANAGED_TRANSPORT_VER=1 TOR_PT_CLIENT_TRANSPORTS=meek /usr/bin/meek-client --log meek-client.log

It should produce on the terminal:

VERSION 1
CMETHOD meek socks5 127.0.0.1:38561
CMETHODS DONE

meek-client.log should contain at least:

2016/10/25 15:42:28 listening on 127.0.0.1:38561

(Of course the port number may be different.)

comment:4 in reply to:  3 ; Changed 13 months ago by tagener-noisu

Replying to dcf:

You might have to report this bug to the maintainer of the AUR package.

What do you get when you run this command?

TOR_PT_MANAGED_TRANSPORT_VER=1 TOR_PT_CLIENT_TRANSPORTS=meek /usr/bin/meek-client --log meek-client.log

It should produce on the terminal:

VERSION 1
CMETHOD meek socks5 127.0.0.1:38561
CMETHODS DONE

meek-client.log should contain at least:

2016/10/25 15:42:28 listening on 127.0.0.1:38561

(Of course the port number may be different.)

Everything is ok, I've got this:

VERSION 1
CMETHOD meek socks5 127.0.0.1:44461
CMETHODS DONE

And a log file here:

2016/10/26 15:55:44 listening on 127.0.0.1:44461
2016/10/26 15:55:52 got signal interrupt
2016/10/26 15:55:52 done

I interrupted it with C-c.

comment:5 in reply to:  4 ; Changed 13 months ago by dcf

Replying to tagener-noisu:

Everything is ok, I've got this:
And a log file here:

Hm, I don't know what to suggest. You can try increasing the tor log verbosity from "notice" to "info":

Log info syslog

That should give you some more information about it starting its subprocesses.

Is it possible you have some kind of hardening like seccomp or apparmor that applies to tor? That might be restricting what it can do with its child processes. Are you able to use an obfs4 bridge with obfs4proxy?

comment:6 in reply to:  5 Changed 13 months ago by tagener-noisu

Replying to dcf:

Hm, I don't know what to suggest. You can try increasing the tor log verbosity from "notice" to "info":

Log info syslog

Still nothing usefull in the log.

Oct 26 23:54:13 laptop Tor[32547]: launch_managed_proxy(): Managed proxy at '/usr/bin/meek-client' has spawned with PID '32555'.
Oct 26 23:54:13 laptop Tor[32547]: cell_ewma_set_scale_factor(): Disabled cell_ewma algorithm because of value in Default value
Oct 26 23:54:13 laptop Tor[32547]: Parsing GEOIP IPv4 file /usr/share/tor/geoip.
Oct 26 23:54:13 laptop Tor[32547]: Parsing GEOIP IPv6 file /usr/share/tor/geoip6.
Oct 26 23:54:13 laptop Tor[32547]: crypto_global_init(): NOT using OpenSSL engine support.
Oct 26 23:54:13 laptop Tor[32547]: evaluate_evp_for_aes(): This version of OpenSSL has a known-good EVP counter-mode implementation. Using it.
Oct 26 23:54:13 laptop Tor[32547]: Bootstrapped 0%: Starting
Oct 26 23:54:13 laptop Tor[32547]: trusted_dirs_load_certs_from_string(): Adding cached certificate for directory authority Faravahar with signing key 81FFA14EDAECD6CD8167A81556643486A7D30077
Oct 26 23:54:13 laptop Tor[32547]: trusted_dirs_load_certs_from_string(): Not adding cached certificate for unrecognized directory authority with signing key 11160AE7FE48BEBE4716E8CD4ED9711FD9E3DDBF
Oct 26 23:54:13 laptop Tor[32547]: trusted_dirs_load_certs_from_string(): Adding cached certificate for directory authority tor26 with signing key 30F18E63064ECEB50C4D6339F5F6B12F9D6671DA
Oct 26 23:54:13 laptop Tor[32547]: trusted_dirs_load_certs_from_string(): Adding cached certificate for directory authority longclaw with signing key B54530637B8E758C5CB008ADF2BDB4D86DD74946
Oct 26 23:54:13 laptop Tor[32547]: trusted_dirs_load_certs_from_string(): Adding cached certificate for directory authority maatuska with signing key E9E6767366FB9056675D7A99B1D3E4F712752C81
Oct 26 23:54:13 laptop Tor[32547]: trusted_dirs_load_certs_from_string(): Adding cached certificate for directory authority moria1 with signing key 25EA246B93803795E871FBA60C1A4D6224A837F8
Oct 26 23:54:13 laptop Tor[32547]: trusted_dirs_load_certs_from_string(): Adding cached certificate for directory authority gabelmoo with signing key 9E5ECDF8D87A1B11C000A11B57AEB31D2EE48A72
Oct 26 23:54:13 laptop Tor[32547]: trusted_dirs_load_certs_from_string(): Adding cached certificate for directory authority dizum with signing key 2FD3DEFEA7E7965FB10ABF316E188DDB638AD506
Oct 26 23:54:13 laptop Tor[32547]: read_file_to_str(): Could not open "/var/lib/tor/cached-consensus": No such file or directory
Oct 26 23:54:13 laptop Tor[32547]: read_file_to_str(): Could not open "/var/lib/tor/unverified-consensus": No such file or directory
Oct 26 23:54:13 laptop Tor[32547]: read_file_to_str(): Could not open "/var/lib/tor/unverified-microdesc-consensus": No such file or directory
Oct 26 23:54:13 laptop Tor[32547]: microdesc_cache_reload(): Reloaded microdescriptor cache. Found 7906 descriptors.
Oct 26 23:54:13 laptop Tor[32547]: tor_mmap_file(): Could not open "/var/lib/tor/cached-descriptors" for mmap(): No such file or directory
Oct 26 23:54:13 laptop Tor[32547]: tor_mmap_file(): Could not open "/var/lib/tor/cached-extrainfo" for mmap(): No such file or directory
Oct 26 23:54:13 laptop Tor[32547]: compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
Oct 26 23:54:13 laptop Tor[32547]: should_delay_dir_fetches(): Delaying dir fetches (no running bridges known)
Oct 26 23:54:13 laptop Tor[32547]: Delaying directory fetches: No running bridges
Oct 26 23:54:13 laptop Tor[32547]: I learned some more directory information, but not enough to build a circuit: No running bridges
Oct 26 23:54:13 laptop Tor[32547]: compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
Oct 26 23:54:13 laptop Tor[32547]: should_delay_dir_fetches(): Delaying dir fetches (no running bridges known)
Oct 26 23:54:13 laptop Tor[32547]: compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
Oct 26 23:54:13 laptop Tor[32547]: should_delay_dir_fetches(): Delaying dir fetches (no running bridges known)
Oct 26 23:54:14 laptop Tor[32547]: compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
Oct 26 23:54:14 laptop Tor[32547]: should_delay_dir_fetches(): Delaying dir fetches (no running bridges known)
Oct 26 23:54:14 laptop Tor[32547]: compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
Oct 26 23:54:14 laptop Tor[32547]: should_delay_dir_fetches(): Delaying dir fetches (no running bridges known)
Oct 26 23:54:14 laptop Tor[32547]: compute_weighted_bandwidths(): Empty routerlist passed in to consensus weight node selection for rule weight as guard
Oct 26 23:54:14 laptop Tor[32547]: should_delay_dir_fetches(): Delaying dir fetches (no running bridges known)
Oct 26 23:54:14 laptop Tor[32547]: or_state_save(): Saved state to "/var/lib/tor/state"
Oct 26 23:54:14 laptop Tor[32547]: The communication stream of managed proxy '/usr/bin/meek-client' is 'closed'. Most probably the managed proxy stopped running. This might be a bug of the managed proxy, a bug of Tor, or a misconfiguration. Please enable logging on your managed proxy and check the logs for errors.

Is it possible you have some kind of hardening like seccomp or apparmor that applies to tor? That might be restricting what it can do with its child processes. Are you able to use an obfs4 bridge with obfs4proxy?

No I don't have anything like that. obfs-proxies don't work anymore in my country - that's why I'm trying to use meek. I've left a message on AUR's page of the my package, I will try to figure out what's wrong.

comment:7 Changed 13 months ago by tnoisu

Resolution: fixed
Status: newclosed

Hi, I can't login into my old account tagener-noisu, so I have created another one. The problem was that meek wasn't able to create a log file in the working directory. I've changed the log path like this --log /tmp/meek-client.log to fix it. I think that meek should just work without logging if it couldn't create a log file. Should I report this issue to developer's github?

Last edited 13 months ago by tnoisu (previous) (diff)

comment:8 in reply to:  7 Changed 8 months ago by dcf

Resolution: fixed
Status: closedreopened

Replying to tnoisu:

Hi, I can't login into my old account tagener-noisu, so I have created another one. The problem was that meek wasn't able to create a log file in the working directory. I've changed the log path like this --log /tmp/meek-client.log to fix it. I think that meek should just work without logging if it couldn't create a log file. Should I report this issue to developer's github?

I'm the developer so this is the right place to report it. Sorry for the delay.

I don't like the idea of silently continuing if the log file fails to open. The way it fails now is pretty bad though, because it leaves no trace of an error message.

It would be good if an error message appeared in tor's log, even if the pluggable transport can't write its own log file. Unfortunately, the pluggable transports spec doesn't really give us a way to report general errors. We could abuse the CMETHOD-ERROR or PROXY-ERROR messages; those appear in tor's log. CMETHOD-ERROR appears like this:

[warn] Client managed proxy encountered a method error. (meek error opening log file: open meek-client.log: permission denied)
[warn] Managed proxy at './meek-client' failed the configuration protocol and will be destroyed.

PROXY-ERROR appears like this:

[warn] Managed proxy failed to configure the pluggable transport's outgoing proxy. (error opening log file: open meek-client.log: permission denied)
[warn] Managed proxy at './meek-client' failed the configuration protocol and will be destroyed.

Of these two options, CMETHOD-ERROR seems better than PROXY-ERROR because it won't add a misleading message about a proxy in the log. It's not totally correct because we're not supposed to emit a CMETHOD-ERROR unless we're asked for a specific client method, and we would be emitting this error very early, before even looking at the list of client methods. However, I don't think it will be a problem in practice.

attachment:0001-Emit-a-CMETHOD-ERROR-or-SMETHOD-ERROR-when-failing-t.patch is an example patch for review.

comment:9 Changed 8 months ago by dcf

Status: reopenedneeds_review

comment:10 Changed 8 months ago by asn

Eek. I guess the proper long-term fix here involves introducing another error type that can be emited mid-run? For example, PT-ERROR or GENERAL-ERROR or something?

Abusing CMETHOD-ERROR seems like a reasonable choice for the short-term.

comment:11 in reply to:  10 Changed 8 months ago by dcf

Replying to asn:

Eek. I guess the proper long-term fix here involves introducing another error type that can be emited mid-run? For example, PT-ERROR or GENERAL-ERROR or something?

Abusing CMETHOD-ERROR seems like a reasonable choice for the short-term.

In the past, we discussed (and even had a patch for) treating anything written to stderr as an error message: #9957. It even mentions this exact use case:

obfsproxy may complain about some things (e.g. it not being able to write to its own log file) over stderr. If one runs obfsproxy as intended (using the ServerTransportPlugin directive in torrc), obfsproxy may exit (Tor will report this, of course) without any verbal explanation.

comment:9:ticket:12088 discusses using ENV-ERROR (although in my recent tests, ENV-ERROR isn't reflected in the tor logs?) and the desire for something like GENERIC-ERROR:

About error reporting: suppose your transport needs to create its own subdirectories in the state dir. You call pt.MakeStateDir, then you manually create the directories inside it. Suppose the creation of one of these directories fails. Is that an ENV-ERROR? If not, then a failure to create the state dir itself probably should also not be an ENV-ERROR. (Except to the extent that we abuse ENV-ERROR as a general-purpose error logging function.)

This is true. As far as what the API does, I would prefer it to always ENV-ERROR, or never so the error handling in the applications can do the right thing (and if the latter, I will more than likely continue to abuse ENV-ERROR as a general purpose error reporting mechanism till something better comes around, because providing 0 feedback to the actual user is terrible).

CMETHOD-ERROR/SMETHOD-ERROR could be a good way to report these kinds of generic errors that happen at startup. "CMETHOD-ERROR foo failed to create state directory." The only thing is I bet application authors want to handle all the state dir stuff once at the top of their program, before they enter the CMETHOD processing loop. It kind of makes me wish for a GENERIC-ERROR that could appear at any time during negotiation.

I kind of like the #9957 approach here ("Spam errors to stderr, tor will propagate the complaints to interested parties"). It's simple, and the code is technically done, so it's more likely to exist sooner than adding new statements to the PT protocol.

comment:12 Changed 8 months ago by dcf

Resolution: fixed
Status: needs_reviewclosed

I merged the CMETHOD/SMETHOD hack in 017d0f33d7.

Note: See TracTickets for help on using tickets.