Launch of v2.70.1 fails in startup on some instances

[NSkelsey]

Current behavior

In the wild we have seen the following failure.

2017-06-29 18:13:49+0200 [-] Log opened.
2017-06-29 18:13:49+0200 [-] twistd 16.0.0 (/usr/bin/python 2.7.12) starting up.
2017-06-29 18:13:49+0200 [-] reactor class: twisted.internet.epollreactor.EPollReactor.
2017-06-29 18:13:49+0200 [-] [E] Found an already initialized database version: 37
2017-06-29 18:13:49+0200 [-] [E] Performing data update
2017-06-29 18:13:49+0200 [-] [E] ERROR: Cannot start GlobaLeaks. Please manually examine the exception.
2017-06-29 18:13:49+0200 [-] [E] EXCEPTION: An error occurred while connecting: 13: Permission denied.
2017-06-29 18:13:49+0200 [-] Main loop terminated.
2017-06-29 18:13:49+0200 [-] Server Shut Down.

The exception An error occured while connecting is from a twisted.internet.error.ConnectError. I believe it is coming from the socket allocation code that we have changed in 8d65a7103a49cc025c1f31959a4f9c2d603ee1eb. It could also be related to removal of custom ports for hosting the proxy.

Expected behavior

Startup should execute cleanly.

GlobaLeaks version:

v2.70.1

Server Operating System and Version (if applicable):

Xenial (16.04)

[kyrylkov]

More info:

Starting GlobaLeaks…
Enabling development mode for sergiy
Going in background; log available at /usr/lib/python2.7/dist-packages/workingdir/log/globaleaks.log
Serving the client from directory: /usr/share/globaleaks/client/
Error in creating directory: /usr/lib/python2.7/dist-packages/workingdir (Permission denied)
Traceback (most recent call last):
  File "/usr/bin/globaleaks", line 144, in <module>
    GLSettings.create_directories()
  File "/usr/lib/python2.7/dist-packages/globaleaks/settings.py", line 413, in create_directories
    self.create_directory(dirpath)
  File "/usr/lib/python2.7/dist-packages/globaleaks/settings.py", line 391, in create_directory
    raise excep
OSError: [Errno 13] Permission denied: '/usr/lib/python2.7/dist-packages/workingdir'

[evilaliv3]

Thanks @kyrylkov for sharing this additional detail.

This second error is only related to the -z parameter, intended to be used only in development with a local setup of globaleaks; this is the reason why the working dir has been searched in /usr/lib/python2.7/dist-packages/workingdir instead in /var/globaleaks. I will protect from this condition in the source code because its a wrong mistake.

Try to run not with -z but just with -l DEBUG, and even better just set the following in /etc/default/globaleaks:

• LOGLEVEL=DEBUG

then restart globaleaks and look at what you get in ```/var/globaleaks/log/globaleaks.log

[kyrylkov]

@evilaliv3

didn't make it more verbose:

root@x2:~# cat /etc/default/globaleaks
# This is a configuration file for /etc/init.d/globaleaks;
# it allows you to perform common modifications to the behavior
# of the globaleaks daemon.
#
# Default settings can be found at: /usr/share/globaleaks/default
#NETWORK_SANDBOXING=1
LOGLEVEL=DEBUG
root@x2:~# service globaleaks restart
root@x2:~# tail /var/globaleaks/log/globaleaks.log
2017-06-29 20:34:42+0200 [-] Log opened.
2017-06-29 20:34:42+0200 [-] twistd 16.0.0 (/usr/bin/python 2.7.12) starting up.
2017-06-29 20:34:42+0200 [-] reactor class: twisted.internet.epollreactor.EPollReactor.
2017-06-29 20:34:42+0200 [-] [E] Found an already initialized database version: 37
2017-06-29 20:34:42+0200 [-] [E] Performing data update
2017-06-29 20:34:42+0200 [-] [I] Starting up Tor connection
2017-06-29 20:34:42+0200 [-] [E] ERROR: Cannot start GlobaLeaks. Please manually examine the exception.
2017-06-29 20:34:42+0200 [-] [E] EXCEPTION: An error occurred while connecting: 13: Permission denied.
2017-06-29 20:34:42+0200 [-] Main loop terminated.
2017-06-29 20:34:42+0200 [-] Server Shut Down.

[evilaliv3]

i see. actually we do not have more verbose logs on this part but was important to verify.

probably Tor is not starting and you are getting this error. the expected behaviour in this release is to have GlobaLeaks connected to Tor on the unix socket:

root@remotehost:/home/evilaliv3/Devel/GlobaLeaks# ls /var/run/tor/control -al
srw-rw---- 1 debian-tor debian-tor 0 giu 27 23:50 /var/run/tor/control

do you have this file with this permissions right?

the globaleaks user should be in the debian-tor group; could you verify it looking at in /etc/groups?

anyway this was not expected to be a possible failure preventing the application to start but it seems so.

we are continuing investigating and i will let you know if we have updates.

[kyrylkov]

Yes, we have the file with the same permissions:

root@x2:~# ls /var/run/tor/control -al
srw-rw---- 1 debian-tor debian-tor 0 Jun 29 18:18 /var/run/tor/control

Yes, we have globaleaks in debiat-tor group:

root@x2:~# cat /etc/group
...........
debian-tor:x:114:globaleaks
...........

[fpietrosanti]

Let's move to hardcore debugging:

apt-get install strace /etc/init.d/globaleaks stop strace -f -v -o /tmp/strace.out /etc/init.d/globaleaks start

Then send by email the file strace.out containing any kind of file system operation and this will tell us which is the i/o operation failing

Thanks for the hell in debugging!

Sent from mobile

Sent from Cassette Tape Recorder

On 29 Jun 2017, at 21:41, Sergiy Kyrylkov notifications@github.com wrote:

Hi Giovanni,

Yes, we have the file with the same permissions:

http://LTPK.trk.elasticemail.com/tracking/unsubscribe?msgid=drGLm4nGRQGrk1-gPlvOsw2

[fpietrosanti]

Which are the tcp listening ports on the system? Output of: netstat -ntlp

[fpietrosanti]

Does "dmesg | egrep -i denied" show some kind of output? (Maybe apparmor blocking some operations) ?

[kyrylkov]

@fpietrosanti

root@x2:~# netstat -ntlp
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      1060/sshd
tcp        0      0 127.0.0.1:9050          0.0.0.0:*               LISTEN      1112/tor
tcp6       0      0 :::22                   :::*                    LISTEN      1060/sshd

root@x2:~# dmesg | egrep -i denied
[ 8132.567213] audit: type=1400 audit(1498761227.994:13): apparmor="DENIED" operation="connect" info="Failed name lookup - disconnected path" error=-13 profile="usr.bin.globaleaks" name="run/tor/control" pid=2963 comm="globaleaks" requested_mask="wr" denied_mask="wr" fsuid=1337 ouid=106
[ 8186.822691] audit: type=1400 audit(1498761282.250:14): apparmor="DENIED" operation="connect" info="Failed name lookup - disconnected path" error=-13 profile="usr.bin.globaleaks" name="run/tor/control" pid=3059 comm="globaleaks" requested_mask="wr" denied_mask="wr" fsuid=1337 ouid=106
[12658.128506] audit: type=1400 audit(1498765753.560:15): apparmor="DENIED" operation="connect" info="Failed name lookup - disconnected path" error=-13 profile="usr.bin.globaleaks" name="run/tor/control" pid=5257 comm="globaleaks" requested_mask="wr" denied_mask="wr" fsuid=1337 ouid=106

[evilaliv3]

Sergy could you try the following patch to /etc/apparmor.d/usr.bin.globaleaks and perform apparmor/globaleaks restart?

https://github.com/globaleaks/GlobaLeaks/commit/3fedaa16d821eb75526657752b2490b6904effe8

to restart apparmor and globaleaks perform in the order:

service apparmor restart
service globaleaks restart

[kyrylkov]

@evilaliv3 didn't help

[evilaliv3]

Did the error remain the same exact of before?

(just as a dumb retest could you restart the system; maybe for some reason apparmor is not reloading just with that command);

i was expecting the error to change and eventually as i think you are running on xenial/systemd, to have to deal with it but at least to have solved the apparmor issue

[kyrylkov]

@evilaliv3

We did restart.

The error is the same:

2017-06-30 11:19:09+0200 [-] Log opened.
2017-06-30 11:19:09+0200 [-] twistd 16.0.0 (/usr/bin/python 2.7.12) starting up.
2017-06-30 11:19:09+0200 [-] reactor class: twisted.internet.epollreactor.EPollReactor.
2017-06-30 11:19:09+0200 [-] [E] Found an already initialized database version: 37
2017-06-30 11:19:09+0200 [-] [E] Performing data update
2017-06-30 11:19:09+0200 [-] [I] Starting up Tor connection
2017-06-30 11:19:09+0200 [-] [E] ERROR: Cannot start GlobaLeaks. Please manually examine the exception.
2017-06-30 11:19:09+0200 [-] [E] EXCEPTION: An error occurred while connecting: 13: Permission denied.
2017-06-30 11:19:09+0200 [-] Main loop terminated.
2017-06-30 11:19:09+0200 [-] Server Shut Down.

[evilaliv3]

Could you provide also the log of apparmor visualized in dmesg this time?

[kyrylkov]

root@x2:~# dmesg | egrep -i denied
[   16.432775] audit: type=1400 audit(1498814349.581:12): apparmor="DENIED" operation="connect" info="Failed name lookup - disconnected path" error=-13 profile="usr.bin.globaleaks" name="run/tor/control" pid=1551 comm="globaleaks" requested_mask="wr" denied_mask="wr" fsuid=1337 ouid=106

[evilaliv3]

Thanks, we will now retry ourselves on a machine with apparmor and be back to you.

I'm sorry for the inconvenience.

[evilaliv3]

Hi @kyrylkov

we just releasd a 2.70.2 working specifically on the topic you were having issues on.

The release uses the stock Tor version (greater or equal than 0.2.9.11) that is currently available only on the Tor repository.

To proceed you should re-run the updated install script that fix the preconditions for the package install (fix some of the repositories sources) or fix them by yourself looking at what the script does. The script has been anyhow thought multiple times so that even in the future if a specific issues fix does not exists you may considering just updating using the up to date install script.

before proceeding just in doubt make a copy of the /var/globaleaks for eventual recovery (nothing should happen) in case of failures.

https://raw.githubusercontent.com/globaleaks/GlobaLeaks/master/scripts/install.sh

please let us know if this helped.

[fpietrosanti]

apparmor problems fixed