xpra icon
Bug tracker and wiki

Opened 5 years ago

Closed 5 years ago

Last modified 5 years ago

#946 closed defect (fixed)

Unable to stop Xpra server if AES encryption is enabled

Reported by: J. Max Mena Owned by: Antoine Martin
Priority: blocker Milestone: 0.16
Component: server Version: 0.14.x
Keywords: Cc:

Description

Running a Fedora 21 trunk r10308 server (no clients..):

  • Server started with xpra start :13 --no-daemon --encryption=AES --password-file=/home/max/password.txt

Attempting to stop the server with xpra stop :13 --encryption=AES --password-file=/home/max/password.txt fails with the following prints:

Server side:


2015-08-14 15:57:14,712 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-14 15:57:14,713 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-14 15:57:14,717 Connection lost
2015-08-14 15:57:14,781 sending data using AES encryption
2015-08-14 15:57:14,824 receiving data using AES encryption
2015-08-14 15:57:14,866 Authentication required, Password File Authenticator sending challenge for 'max' using digest hmac
2015-08-14 15:57:15,040 Python/GObject Linux client version 0.16.0
2015-08-14 15:57:15,041  connected from 'schlafanzug.spikes.eng' as 'max'
2015-08-14 15:57:15,042 internal error: encryption error (wrong key?)
2015-08-14 15:57:15,043 xpra client disconnected.
2015-08-14 15:57:34,812 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-14 15:57:34,813 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-14 15:57:34,814 Connection lost
2015-08-14 15:57:34,815 Connection lost
2015-08-14 15:57:35,314 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-14 15:57:35,315 Connection lost
2015-08-14 15:57:35,815 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-14 15:57:35,816 Connection lost
2015-08-14 15:57:36,316 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-14 15:57:36,317 Connection lost
2015-08-14 15:57:36,816 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-14 15:57:36,818 Connection lost
2015-08-14 15:57:37,317 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-14 15:57:37,319 Connection lost


And client side:

[max@schlafanzug ~]$ xpra stop :13 --encryption=AES --password-file=/home/max/password.txt
receiving data using AES encryption
sending data using AES encryption
timeout: server did not disconnect us
Failed to shutdown xpra at :13

Attempting the same commands without --encryption=AES (xpra start :13 --no-daemon --password-file=/home/max/password.txt xpra stop :13 --password-file=/home/max/password.txt) works as expected.

Attachments (1)

crypto-log.patch (1.8 KB) - added by Antoine Martin 5 years ago.
enables logging for the encryption and decryption of raw packet data (for debugging)

Download all attachments as: .zip

Change History (9)

comment:1 Changed 5 years ago by Antoine Martin

Priority: majorblocker
Status: newassigned
Version: trunk0.14.x

Confirmed, this is very odd:

  • some subcommands work: info, attach, control, screenshot...
  • others don't: stop, version

Running with -d auth,network, the server shows:

2015-08-15 23:20:13,529 received 32 encrypted bytes with 12 padding
2015-08-15 23:20:13,529 decryption failed: string does not end with '











                                                                     ' \
or '            ': \
[131, 88, 198, 98, 102, 0, 228, 46, 171, 157, 102, 17, 207, 117, 20, 40, 249, 8, 82, 199, 192, 247, 63, 28, 179, 183, 254, 217, 83, 13, 159, 92] (<type 'str'>) \
-> [57, 205, 42, 88, 83, 137, 223, 217, 247, 42, 44, 124, 123, 11, 250, 195, 47, 75, 150, 191, 9, 9, 253, 175, 76, 165, 174, 253, 192, 100, 136, 2] (<type 'str'>)

This affects all supported versions.

Last edited 5 years ago by Antoine Martin (previous) (diff)

comment:2 Changed 5 years ago by Antoine Martin

With all this applied, I can stop the server using a py3k client, but still not from a python2 client!?

Here's the new and improved server error with a python2 client triggering the problem:

Warning: AES decryption failed: invalid padding
 data does not end with bytes 0c0c0c0c0c0c0c0c0c0c0c0c
 or 202020202020202020202020
 but with 9f8f98c38a44e4cd68b23912 (<type 'str'>)
 decrypted data: 57b72288f8be4721c605a46871f96bd30bd6d32b9f8f98c38a44e4cd68b23912
internal error: AES encryption padding error - wrong key?
Last edited 5 years ago by Antoine Martin (previous) (diff)

comment:3 Changed 5 years ago by Antoine Martin

This bug just gets weirder as you look at it, heseinbug of sorts.
Minor improvements to the network code to ease debugging and testing (r10327) were followed by a minor change to reduce the amount of initial "hello" packet data we send for short-lived clients like "stop" and "version" (which reduces the amount of data getting logged, which makes it easier to debug)... and now the AES padding error is gone! But I get a bdecoder error instead!?

Error parsing bencode packet:
 invalid bencoded string type identifier: -87 at position 0
failed to parse bencode packet: a9da2f6923cd33e29166847d9dba854b76657265

Maybe it's compressed and we're not decompressing it, or something.

Changed 5 years ago by Antoine Martin

Attachment: crypto-log.patch added

enables logging for the encryption and decryption of raw packet data (for debugging)

comment:4 Changed 5 years ago by Antoine Martin

The python2 failures are fixed in r10332 (with some preliminary minor fixups in r10330): we just needed to reset the crypto options before sending another packet. Some subcommands send their request embedded in the hello packet and don't need to bother with this, "stop" uses a dedicated packet and must have the up to date crypto parameters.

Last edited 5 years ago by Antoine Martin (previous) (diff)

comment:5 Changed 5 years ago by Antoine Martin

python3 worked because I didn't have python3-pycrypto installed, and so it didn't use crypto at all!
r10334 changes this into an error: if the user specifies encryption, it should be used!

comment:6 Changed 5 years ago by Antoine Martin

r10335 allows us to more easily test the "without crypto" codepaths, even when pycrypto is already installed:

XPRA_ENABLE_CRYPTO=0 python3 /usr/bin/xpra --encryption=AES --password-file=./password.txt stop :13

See also #951.

@maxmylyn: does this work for you?

comment:7 Changed 5 years ago by J. Max Mena

Upped to r10336 trunk:

Started a server with xpra start :13 --no-daemon(to watch prints) --encryption=AES --password-file=/home/max/password.txt

  • Server stopped as expected with xpra stop :13 --encryption=AES --password-file=/home/max/password.txt

Feel free to close at your leisure...


For what it's worth, the logs indicated another connection was received after the shutdown request was given. This may be expected, but I figured I'd point it out as it seems a little odd to me:

2015-08-18 09:12:47,550 Shutting down in response to client request
2015-08-18 09:12:47,551 Disconnecting client '/home/max/.xpra/schlafanzug.spikes.eng-13': server shutdown
2015-08-18 09:12:47,551 xpra client disconnected.
2015-08-18 09:12:47,617 New unix-domain connection received on /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-18 09:12:47,618 socktype=unix-domain, auth class=<class 'xpra.server.auth.file_auth.Authenticator'>, encryption=AES, keyfile=
2015-08-18 09:12:47,620 Connection lost
2015-08-18 09:12:48,056 stopping pulseaudio with pid 2202
2015-08-18 09:12:48,082 Warning: the pulseaudio server process has terminated after 38 seconds
2015-08-18 09:12:48,368 ignoring new connection during shutdown
2015-08-18 09:12:48,576 xpra is terminating.
2015-08-18 09:12:48,577 removing socket /home/max/.xpra/schlafanzug.spikes.eng-13
2015-08-18 09:12:48,577 killing xvfb with pid 2178
(EE) Server terminated successfully (0). Closing log file.

comment:8 Changed 5 years ago by Antoine Martin

Resolution: fixed
Status: assignedclosed

the logs indicated another connection was received after the shutdown request was given


That's the "stop" client trying to figure out if the server has properly shutdown or not.

r10343 improves the code so we don't actually connect for the first 5 seconds after we issue the shutdown request, we only try to connect if it looks like things are going to time out. (not going to backport - this is mostly cosmetic)

Backports in r10344, r10348, r10334. (and briefly run tested each branch)

See also: #951.

Last edited 5 years ago by Antoine Martin (previous) (diff)
Note: See TracTickets for help on using tickets.