After attempted upgrade, Tor not running, can't restart it

anonimuso · September 1, 2020, 6:34am

Hello, I have been using Whonix for a while now. Today I started an upgrade using ‘sudo apt-get dist-upgrade’. I did this on the workstation first, then on the gateway. Unfortunately the gateway froze and it seemed that nothing was happening after a good while, so I force closed. Probably a bad idea. When I restarted the gateway, whonixcheck came up with the following error:

ERROR: Tor Pid Check Result:
Tor not running. (tor_pid_message: Pid file /run/tor/tor.pid does not exist.)

And when I try to do an upgrade or update, I get this:

Ign:1 tor+https://deb.debian.org/debian-security buster/updates InRelease
Ign:2 tor+https://deb.debian.org/debian buster InRelease
Ign:3 tor+https://deb.whonix.org buster InRelease
Ign:1 tor+https://deb.debian.org/debian-security buster/updates InRelease
Ign:3 tor+https://deb.whonix.org buster InRelease
Ign:3 tor+https://deb.whonix.org buster InRelease
Ign:2 tor+https://deb.debian.org/debian buster InRelease
Err:3 tor+https://deb.whonix.org buster InRelease
Could not connect to 127.0.0.1:9050 (127.0.0.1). - connect (111: Connection refused)
Ign:1 tor+https://deb.debian.org/debian-security buster/updates InRelease
Ign:2 tor+https://deb.debian.org/debian buster InRelease
Err:1 tor+https://deb.debian.org/debian-security buster/updates InRelease
Could not connect to 127.0.0.1:9050 (127.0.0.1). - connect (111: Connection refused)
Err:2 tor+https://deb.debian.org/debian buster InRelease
Unable to connect to 127.0.0.1:9050:
Reading package lists… Done
W: Failed to fetch tor+https://deb.debian.org/debian-security/dists/buster/updates/InRelease Could not connect to 127.0.0.1:9050 (127.0.0.1). - connect (111: Connection refused)
W: Failed to fetch tor+https://deb.debian.org/debian/dists/buster/InRelease Unable to connect to 127.0.0.1:9050:
W: Failed to fetch tor+https://deb.whonix.org/dists/buster/InRelease Could not connect to 127.0.0.1:9050 (127.0.0.1). - connect (111: Connection refused)
W: Some index files failed to download. They have been ignored, or old ones used instead.

I tried restarting Tor and rebooting, but no luck. Is there a way to fix this or will I have to start all over with a clean install of whonix? That would suck because I have everything set up just the way I want it.

HulaHoop · September 1, 2020, 12:39pm

There was a similar bug report in the past. Can you please follow the steps Patrick asked for in this ticket and post the results?

https://github.com/Whonix/Whonix/issues/123

anonimuso · September 1, 2020, 10:30pm

Ok, I have run all of the commands from that topic. Here are the results:

ls -l /var/run/tor

total 0

ls -l /var/run/tor/tor.pid

ls: cannot access ‘/var/run/tor/tor.pid’: No such file or directory

cat /var/run/tor/tor.pid

cat: /var/run/tor/tor.pid: No such file or directory

grep “TORPIDDIR=” /etc/init.d/tor

TORPIDDIR=/run/tor

grep “tor.pid” /etc/init.d/tor

TORPID=$TORPIDDIR/tor.pid

test -f /var/run/tor/tor.pid ; echo $?

1

test -e /var/run/tor/tor.pid ; echo $?

1

Patrick · September 2, 2020, 9:34am

Do Tor Configuration Check.

Then try Tor Log Analysis.

anonimuso · September 3, 2020, 5:08am

Ok. When I ran the Tor config check, I got the following: (sorry, not allowed to post pictures yet)

/===================================================================
| Report Summary |
===================================================================/
No error detected in your Tor configuration.
Tor verify exit code: 0
/===================================================================
| Tor Full Report |
===================================================================/
Sep 01 22:51:24.646 [notice] Tor 0.4.2.7 running on Linux with Libevent 2.1.8-stable, OpenSSL 1.1.1d, Zlib 1.2.11, Liblzma 5.2.4, and Libzstd 1.3.8.
Sep 01 22:51:24.646 [notice] Tor can’t help you if you use it wrong! Learn how to be safe at (link not allowed)
Sep 01 22:51:24.646 [notice] Read configuration file “/usr/share/tor/tor-service-defaults-torrc”.
Sep 01 22:51:24.646 [notice] Read configuration file “/etc/tor/torrc”.
Sep 01 22:51:24.647 [notice] Included configuration file or directory at recursion level 2: “/usr/local/etc/torrc.d/”.
Sep 01 22:51:24.647 [notice] Included configuration file or directory at recursion level 1: “/etc/torrc.d/”.
Sep 01 22:51:24.647 [notice] You configured a non-loopback address ‘10.152.152.10:5300’ for DNSPort. This allows everybody on your local network to use your machine as a proxy. Make sure this is what you wanted.
Sep 01 22:51:24.647 [notice] You configured a non-loopback address ‘10.152.152.10:9040’ for TransPort. This allows everybody on your local network to use your machine as a proxy. Make sure this is what you wanted.
Sep 01 22:51:24.648 [warn] You are running Tor as root. You don’t need to, and you probably shouldn’t.
Configuration was valid
/===================================================================
| Used Tor Configuration Files |
===================================================================/
5 files are used as Tor configuration files:
/usr/share/tor/tor-service-defaults-torrc /etc/tor/torrc /etc/torrc.d/95_whonix.conf /usr/local/etc/torrc.d/40_tor_control_panel.conf /usr/local/etc/torrc.d/50_user.conf

When I did the log analysis using the persistent Tor log command, I got an empty document with the name ‘log.XXbPd04l’ and the following console output:

user@host:~$ sudoedit /var/log/tor/log

(mousepad:4355): dbind-WARNING **: 22:44:30.908: Error retrieving accessibility bus address: org.freedesktop.DBus.Error.ServiceUnknown: The name org.a11y.Bus was not provided by any .service files

(mousepad:4355): Gtk-WARNING **: 22:44:31.054: Theme parsing error: :2:29: The style property GtkButton:default-border is deprecated and shouldn’t be used anymore. It will be removed in a future version

(mousepad:4355): Gtk-WARNING **: 22:44:31.054: Theme parsing error: :3:37: The style property GtkButton:default-outside-border is deprecated and shouldn’t be used anymore. It will be removed in a future version

(mousepad:4355): Gtk-WARNING **: 22:44:31.054: Theme parsing error: :4:27: The style property GtkButton:inner-border is deprecated and shouldn’t be used anymore. It will be removed in a future version

(mousepad:4355): Gtk-WARNING **: 22:44:31.054: Theme parsing error: :5:31: The style property GtkWidget:focus-line-width is deprecated and shouldn’t be used anymore. It will be removed in a future version

(mousepad:4355): Gtk-WARNING **: 22:44:31.054: Theme parsing error: :6:28: The style property GtkWidget:focus-padding is deprecated and shouldn’t be used anymore. It will be removed in a future version

When I ran the Tor log since last boot command, I got this a file named ‘log.XXmsuH7q’ with this written over and over:

Sep 01 05:15:49.000 [notice] You configured a non-loopback address ‘10.152.152.10:9224’ for HTTP TunnelPort. This allows everybody on your local network to use your machine as a proxy. Make sure this is what you wanted.
Sep 01 05:15:49.000 [notice] You configured a non-loopback address ‘10.152.152.10:9225’ for HTTP TunnelPort. This allows everybody on your local network to use your machine as a proxy. Make sure this is what you wanted.
Sep 01 05:15:49.000 [notice] You configured a non-loopback address ‘10.152.152.10:9226’ for HTTP TunnelPort. This allows everybody on your local network to use your machine as a proxy. Make sure this is what you wanted.
Sep 01 05:15:49.000 [notice] You configured a non-loopback address ‘10.152.152.10:9227’ for HTTP TunnelPort. This allows everybody on your local network to use your machine as a proxy. Make sure this is what you wanted.
Sep 01 05:15:49.000 [notice] You configured a non-loopback address ‘10.152.152.10:9228’ for HTTP TunnelPort. This allows everybody on your local network to use your machine as a proxy. Make sure this is what you wanted.
Sep 01 05:15:49.000 [notice] You configured a non-loopback address ‘10.152.152.10:9229’ for HTTP TunnelPort. This allows everybody on your local network to use your machine as a proxy. Make sure this is what you wanted.
Sep 01 05:15:49.000 [notice] Tor 0.4.2.7 opening log file.
Sep 01 05:20:48.000 [notice] New control connection opened.
Sep 01 05:20:48.000 [notice] New control connection opened.
Sep 01 05:20:49.000 [notice] New control connection opened.
Sep 01 05:21:08.000 [notice] New control connection opened.
Sep 01 05:21:08.000 [notice] New control connection opened.
Sep 01 05:21:08.000 [notice] New control connection opened.

Patrick · September 3, 2020, 9:31am

To finish the upgrade:

increase gateway RAM as per Whonix XFCE for VirtualBox users: RAM increase required

sudo dpkg --configure -a

Upgrade normally as per Operating System Software and Updates if you can. Otherwise more things to try as per below:

That looks actually normal. Tor being functional.

Another way to check if Tor is alright…

Open one terminal window. Watch Tor log.

sudo journalctl -u tor@default -f

In another terminal window / or another terminal tab. Restart Tor.

sudo systemctl restart tor@default ; echo $?

Check Tor status.

sudo systemctl status tor@default ; echo $?

Ignore. (Non-Issue → Support Request Policy)

Why would Tor be functional but pid file non-existent? Perhaps some configuration files are not vendor (Whonix) default. To check:

sudo debsums -ce

(Some are expected but file /etc/tor/torrc and files in folder /etc/torrc.d should not be listed there.)

anonimuso · September 4, 2020, 8:46pm

Your post seems to have made some progress, but still not there yet. Looks like the memory limit was part of the issue.

I followed steps 1 and 2, then tried 3, but got an ‘Failed to fetch tor…’ error.

I tried to change the Tor circuit, but running Nyx in terminal gave “Unable to connect to tor. Are you sure it’s running?”

Finally, I reloaded Tor, and ran Nyx again and finally got Tor up and running and was able to update and upgrade. So thank you for that.

But now when I run whonixcheck I get another error:

ERROR: Time Synchronization Result:
Whonixcheck gave up waiting.

Time synchronization status: pending
sdwdate reports: Maximum allowed number of failures reached in pool 1 (3 of 9). Giving up.
If the problem occurs too frequently, please report it.
Sleeping for 0.6666666666666666 minutes.
whonix_firewall status: first run after boot

Possible issues:

sdwdate will need a few more moments for fetching the time.

sdwdate time sources might be dysfunctional.

Recommendations:

A) Rerun whonixcheck:
Start Menu → System → Whonix Check
or in Terminal: whonixcheck
or in Terminal with debugging: whonixcheck --debug --verbose --gui --cli

B) Restart sdwdate.
Start Menu → System → sdwdate-gui → right click on sdwdate-gui systray → Restart sdwdate
or in Terminal: sudo service sdwdate restart

C) Manually set the time.

As last resort…

Open a terminal. (Start Menu → System → Terminal)

Use the manual clock setting tool.
sudo --set-home clock-random-manual-gui

Simulate sdwdate success.
sudo touch /run/sdwdate/first_success

Rerun whonixcheck.

The Time Synchronization Monitor in the status panel has a red x on it and when I open it says:

Last message from sdwdate:

Maximum allowed number of failures reached in pool 1 (3 of 9). Giving up.
If the problem occurs too frequently, please report it.
Sleeping for 0.55 minutes.

I tried restarting the sdwdate and then the VM, but the red x remains and whonixcheck returns the same error. sdwdate log shows:

2020-09-04 20:36:23 - sdwdate - INFO - sclockadj not running, ok.
2020-09-04 20:36:23 - sdwdate - WARNING - Clock got changed by something other than sdwdate. sleep_time_seconds: 9 time_delta: 9
2020-09-04 20:36:23 - sdwdate - INFO - Running sdwdate main loop. iteration: 9 / 10000
2020-09-04 20:36:24 - sdwdate - INFO - Prerequisite check: The clock is sane.
Within build timestamp Sun 27 Oct 2019 10:27:15 AM UTC and expiration timestamp Tue 17 May 2033 10:00:00 AM UTC.
Clock within consensus parameters consensus/valid-after 2020-09-04 19:00:00 and consensus/valid-until 2020-09-04 22:00:00.
2020-09-04 20:36:24 - sdwdate - INFO - Prerequisite check: Tor fully bootstrapped.
2020-09-04 20:36:24 - sdwdate - INFO - Start fetching remote times.
2020-09-04 20:36:24 - sdwdate - INFO - Initial time fetching in progress…
2020-09-04 20:36:24 - sdwdate - INFO - Running sdwdate fetch loop. iteration: 1
2020-09-04 20:36:24 - sdwdate - INFO - Requested urls [‘secrdrop5wyphb5x.onion’, ‘ak2uqfavwgmjrvtu.onion’, ‘deepdot35wvmeyd5.onion’]
2020-09-04 20:36:24 - sdwdate - INFO - Returned urls “[‘secrdrop5wyphb5x.onion’, ‘ak2uqfavwgmjrvtu.onion’, ‘deepdot35wvmeyd5.onion’]”
2020-09-04 20:36:24 - sdwdate - INFO - remote 0: secrdrop5wyphb5x.onion
2020-09-04 20:36:24 - sdwdate - INFO - * comment:
2020-09-04 20:36:24 - sdwdate - INFO - * status: False
2020-09-04 20:36:24 - sdwdate - INFO - * value: b’connect error: Error connecting to SOCKS5 proxy 127.0.0.1:9108: [Errno 111] Connection refused’
2020-09-04 20:36:24 - sdwdate - INFO - remote 1: ak2uqfavwgmjrvtu.onion
2020-09-04 20:36:24 - sdwdate - INFO - * comment: MagyarLeaks 2013 Investigative Journalism Hungary
2020-09-04 20:36:24 - sdwdate - INFO - * status: False
2020-09-04 20:36:24 - sdwdate - INFO - * value: b’connect error: Error connecting to SOCKS5 proxy 127.0.0.1:9108: [Errno 111] Connection refused’
2020-09-04 20:36:24 - sdwdate - INFO - remote 2: deepdot35wvmeyd5.onion
2020-09-04 20:36:24 - sdwdate - INFO - * comment:
2020-09-04 20:36:24 - sdwdate - INFO - * status: False
2020-09-04 20:36:24 - sdwdate - INFO - * value: b’connect error: Error connecting to SOCKS5 proxy 127.0.0.1:9108: [Errno 111] Connection refused’
2020-09-04 20:36:24 - sdwdate - INFO - Running sdwdate fetch loop. iteration: 2
2020-09-04 20:36:24 - sdwdate - INFO - Requested urls [‘mprt35sjunnxfa76.onion’, ‘cyphdbyhiddenbhs.onion’, ‘privacyintyqcroe.onion’]
2020-09-04 20:36:24 - sdwdate - INFO - Returned urls “[‘mprt35sjunnxfa76.onion’, ‘cyphdbyhiddenbhs.onion’, ‘privacyintyqcroe.onion’]”
2020-09-04 20:36:24 - sdwdate - INFO - remote 0: mprt35sjunnxfa76.onion
2020-09-04 20:36:24 - sdwdate - INFO - * comment:
2020-09-04 20:36:24 - sdwdate - INFO - * status: False
2020-09-04 20:36:24 - sdwdate - INFO - * value: b’connect error: Error connecting to SOCKS5 proxy 127.0.0.1:9108: [Errno 111] Connection refused’
2020-09-04 20:36:24 - sdwdate - INFO - remote 1: cyphdbyhiddenbhs.onion
2020-09-04 20:36:24 - sdwdate - INFO - * comment: Cyph - Encrypted Messenger
2020-09-04 20:36:24 - sdwdate - INFO - * status: False
2020-09-04 20:36:24 - sdwdate - INFO - * value: b’connect error: Error connecting to SOCKS5 proxy 127.0.0.1:9108: [Errno 111] Connection refused’
2020-09-04 20:36:24 - sdwdate - INFO - remote 2: privacyintyqcroe.onion
2020-09-04 20:36:24 - sdwdate - INFO - * comment:
2020-09-04 20:36:24 - sdwdate - INFO - * status: False
2020-09-04 20:36:24 - sdwdate - INFO - * value: b’connect error: Error connecting to SOCKS5 proxy 127.0.0.1:9108: [Errno 111] Connection refused’
2020-09-04 20:36:24 - sdwdate - INFO - Running sdwdate fetch loop. iteration: 3
2020-09-04 20:36:24 - sdwdate - INFO - Requested urls [‘propub3r6espa33w.onion’, ‘pgpkeysximvxiazm.onion’, ‘6zwctlqtpilbkl47.onion’]
2020-09-04 20:36:24 - sdwdate - INFO - Returned urls “[‘propub3r6espa33w.onion’, ‘pgpkeysximvxiazm.onion’, ‘6zwctlqtpilbkl47.onion’]”
2020-09-04 20:36:24 - sdwdate - INFO - remote 0: propub3r6espa33w.onion
2020-09-04 20:36:24 - sdwdate - INFO - * comment:
2020-09-04 20:36:24 - sdwdate - INFO - * status: False
2020-09-04 20:36:24 - sdwdate - INFO - * value: b’connect error: Error connecting to SOCKS5 proxy 127.0.0.1:9108: [Errno 111] Connection refused’
2020-09-04 20:36:24 - sdwdate - INFO - remote 1: pgpkeysximvxiazm.onion
2020-09-04 20:36:24 - sdwdate - INFO - * comment:
2020-09-04 20:36:24 - sdwdate - INFO - * status: False
2020-09-04 20:36:24 - sdwdate - INFO - * value: b’connect error: Error connecting to SOCKS5 proxy 127.0.0.1:9108: [Errno 111] Connection refused’
2020-09-04 20:36:24 - sdwdate - INFO - remote 2: 6zwctlqtpilbkl47.onion
2020-09-04 20:36:24 - sdwdate - INFO - * comment:
2020-09-04 20:36:24 - sdwdate - INFO - * status: False
2020-09-04 20:36:24 - sdwdate - INFO - * value: b’connect error: Error connecting to SOCKS5 proxy 127.0.0.1:9108: [Errno 111] Connection refused’
2020-09-04 20:36:24 - sdwdate - INFO - retry_on_error_counter: 8
2020-09-04 20:36:24 - sdwdate - INFO - Maximum allowed number of failures reached in pool 1 (3 of 9). Giving up.
If the problem occurs too frequently, please report it.
Sleeping for 0.7166666666666667 minutes.
2020-09-04 20:36:24 - sdwdate - INFO - Running command: sleep 43.717936444

Do you suggest that I follow step C and set the time manually?

Also, when I ran

sudo debsums -ce

I got no terminal output. Maybe some config files are missing?

Patrick · September 5, 2020, 8:42am

no output = no changed or missing config files → good.

Might still be something wrong with the Tor config.

→ Configuration Check

anon-verify

and

anon-verify --verbose

or even

anon-verify --very-verbose

Then compare that output with a different, functional Whonix-Gateway.

anonimuso · September 8, 2020, 8:12am

Thanks for all the help. But I’ve made some changes to my machine (setting up WSL2) and now Virtualbox isn’t that useful (or usable) anymore. So I think I’ll have to go a different route than Whonix in a VM.

Thanks again.

do23bf7m · September 15, 2020, 11:34am

I have the exact same problem after updating whonix-gw-15!
I restored my Qubes-Whonix with a previous made backup and updated again. Same problem. It is reproducible.

do23bf7m · September 15, 2020, 12:48pm

I played some trial and error (with apt-mark and multiple cloned whonix-gw-15) and found the packet that interrupted the tor connection. I can update everything except this one package: anon-gw-anonymizer-config

Patrick · September 15, 2020, 2:22pm

In that case, try steps from this post:
After attempted upgrade, Tor not running, can't restart it - #8 by Patrick

Also let me know the version numbers. Existing version and new version. Then you, me, anyone can check in how far the package changed between versions. That would help a lot pinpointing the issue.

do23bf7m · September 15, 2020, 7:29pm

anon-gw-anonymizer-config/unknown 3:10.4-1 all [upgradable from: 3:9.9-1]

sys-whonix -> sdwdate log:

sdwdate - WARNING - Tor Bootstrap Result: Tor's Control Port could not be reached.

sys-whonix -> whonixcheck:

user@host:~$ whonixcheck 
[INFO] [whonixcheck] sys-whonix | Whonix-Gateway | whonix-gw-15-clone-1 TemplateBased ProxyVM | Tue 15 Sep 2020 07:37:01 PM UTC
[ERROR] [whonixcheck] Tor Pid Check Result:
Tor not running. (tor_pid_message: Pid file /run/tor/tor.pid does not exist.)

You have to fix this error, before you can use Tor.

Please restart Tor after fixing this error.

    dom0 -> Start Menu -> ServiceVM: sys-whonix -> Restart Tor
    or in Terminal: sudo service tor@default restart

Restart whonixcheck after fixing this error.

   dom0 -> Start Menu -> ServiceVM: sys-whonix -> Whonix Check
    or in Terminal: whonixcheck

sys-whonix -> debsums -ce

user@host:~$ sudo debsums -ce
/etc/apt/sources.list.d/debian.list
/etc/apt/sources.list.d/qubes-r4.list
/etc/xdg/Thunar/uca.xml

sys-whonix -> anon-verify

user@host:~$ anon-verify 
/===================================================================\
|                      Report Summary                               |
\===================================================================/
No error detected in your Tor configuration.

No I get additional this GUI window message:

ERROR: Check sudo Result: System misconfiguration. No panic. No severe issue. Because of this other tests might be malfunctioning too. Command 
sudo /usr/bin/test -x /usr/bin/test ; echo $? 
did not output nothing with exit code zero. Something else happened. 
exit_code output: 0 
sudo_output output: 
sudo: unable to resolve host host: Temporary failure in name resolution

Patrick · September 16, 2020, 7:17am

git diff --stat 9.9-1 10.4-1

changelog.upstream | 100 ++++++++++++++++++++++++++++++++++++
debian/changelog | 30 +++++++++++
etc/apparmor.d/local/system_tor.anondist | 1 +
etc/torrc.d/65_gateway.conf | 9 ++++
lib/systemd/system/anon-gw-anonymizer-config.service | 4 ++
usr/bin/anon-server-to-client-install | 3 ++
usr/lib/anon-gw-anonymizer-config/make-sure-torrc-exist | 11 ++++
usr/share/tor/tor-service-defaults-torrc.anondist | 2 ±
8 files changed, 159 insertions(+), 1 deletion(-)

git diff 9.9-1 10.4-1

Patrick · September 16, 2020, 7:19am

Using seccomp / Sandbox 1? → Cannot use Seccomp in sys-whonix after update

do23bf7m · September 16, 2020, 9:23pm

Yes! They are amazing! Problem solved, Qubes-Whonix runs fine again.
Can you please explain why you knew/suspected that this is the cause of the problem? An answer with a good learning potential would be nice.
In addition to the update, my sdwdate icon in the top bar has changed. Is that normal (now looks like an 8)?

Patrick · September 17, 2020, 10:15am

Glad that was diagnosed.

Because I keep reading Whonix forums and that was the only Tor start issue recently reported. Also I was checking the changes “diff” of the package.

Normal.
Malware, Computer Viruses, Firmware Trojans and Antivirus Scanners