Discussion:
[X2Go-Dev] Error: Wrong version or invalid session authentication cookie/I/O error: ssh_channel_open_session failed. - Socket error: Unknown
Robert Kudyba
2017-12-20 01:52:48 UTC
Permalink
Just started happening today. Something in the new build that could've
caused this? I see an old thread at
http://lists.x2go.org/pipermail/x2go-user/2013-July/001515.html not sure if
it's really the same issue though.


rpm -q x2goserver

x2goserver-4.1.0.0-0.0x2go1.0.git20171218.1453.heuler.fc26.x86_64


server debug log:

Dec 19 20:44:20 sobolev systemd-logind[6573]: New session 1193 of user
kudyba.

Dec 19 20:44:21 sobolev /usr/bin/x2gostartagent[28949]: x2gostartagent
called with options: 800x600 adsl 16m-jpeg-9 unix-kde-depth_32 us query 0 D
XFCE both

Dec 19 20:44:21 sobolev /usr/bin/x2gosessionlimit[28965]: x2gosessionlimit
has been called

Dec 19 20:44:21 sobolev x2golistsessions[28966]: x2golistsessions has been
called with options: --all-servers

Dec 19 20:44:23 sobolev x2gocleansessions[23160]:
kudyba-50-1513734261_stDXFCE_dp32: state file for this session does not
exist: /tmp/.x2go-kudyba/C-kudyba-50-1513734261_stDXFCE_dp32/state (this
can be ignored during session startups)

Dec 19 20:44:23 sobolev /usr/bin/x2gofeature[29088]: x2gofeature called
with options: X2GO_RUN_EXTENSIONS

Dec 19 20:44:23 sobolev
/usr/share/x2go/x2gofeature.d/x2goserver-extensions.features[29093]:
x2goserver-extensions.features called with options: X2GO_RUN_EXTENSIONS

Dec 19 20:44:23 sobolev /usr/bin/x2goserver-run-extensions[29098]:
x2goserver-run-extensions called with options:
kudyba-50-1513734261_stDXFCE_dp32 pre-start

Dec 19 20:44:24 sobolev /usr/bin/x2gostartagent[29111]: creating new
session: kudyba-50-1513734261_stDXFCE_dp32 8e1465b1108ca7aa37f108de97ee7694
29109 65.78.12.82 58571 58572 58573 -1 -1

Dec 19 20:44:24 sobolev /usr/bin/x2gostartagent[29119]: blocking creation
of agent's keyboard file
/tmp/.x2go-kudyba/C-kudyba-50-1513734261_stDXFCE_dp32/keyboard as requested
by session startup command

Dec 19 20:44:24 sobolev /usr/bin/x2gostartagent[29121]: successfully
started X2Go agent session with ID kudyba-50-1513734261_stDXFCE_dp32

Dec 19 20:44:24 sobolev /usr/bin/x2gofeature[29128]: x2gofeature called
with options: X2GO_RUN_EXTENSIONS

Dec 19 20:44:24 sobolev
/usr/share/x2go/x2gofeature.d/x2goserver-extensions.features[29133]:
x2goserver-extensions.features called with options: X2GO_RUN_EXTENSIONS

Dec 19 20:44:24 sobolev /usr/bin/x2goserver-run-extensions[29138]:
x2goserver-run-extensions called with options:
kudyba-50-1513734261_stDXFCE_dp32 post-start

Dec 19 20:44:24 sobolev systemd-logind[6573]: Removed session 1193.

Dec 19 20:44:25 sobolev /usr/bin/x2gosuspend-session[29148]:
x2gosuspend-session called with options: kudyba-51-1513733787_stDMATE_dp32

Dec 19 20:44:25 sobolev /usr/bin/x2gofeature[29163]: x2gofeature called
with options: X2GO_DESKTOPSHARING

Dec 19 20:44:25 sobolev
/usr/share/x2go/x2gofeature.d/x2goserver-extensions.features[29168]:
x2goserver-extensions.features called with options: X2GO_DESKTOPSHARING

Dec 19 20:44:25 sobolev
/usr/share/x2go/x2gofeature.d/x2goserver.features[29173]:
x2goserver.features called with options: X2GO_DESKTOPSHARING

Dec 19 20:44:25 sobolev
/usr/share/x2go/x2gofeature.d/x2goserver-x2goagent.features[29179]:
x2goserver-x2goagent.features called with options: X2GO_DESKTOPSHARING

Dec 19 20:44:25 sobolev
/usr/share/x2go/x2gofeature.d/x2goserver-xsession.features[29184]:
x2goserver-xsession.features called with options: X2GO_DESKTOPSHARING

Dec 19 20:44:25 sobolev /usr/bin/x2gofeature[29191]: x2gofeature called
with options: X2GO_RUN_EXTENSIONS

Dec 19 20:44:25 sobolev
/usr/share/x2go/x2gofeature.d/x2goserver-extensions.features[29197]:
x2goserver-extensions.features called with options: X2GO_RUN_EXTENSIONS

Dec 19 20:44:25 sobolev /usr/bin/x2goserver-run-extensions[29202]:
x2goserver-run-extensions called with options:
kudyba-51-1513733787_stDMATE_dp32 pre-suspend

Dec 19 20:44:25 sobolev x2goumount-session[29210]: x2goumount-session has
been called with options: kudyba-51-1513733787_stDMATE_dp32


client debug log from a Mac:

x2go-DEBUG-../src/onmainwindow.cpp:2851> Creating QPixmap with session
icon: '":/img/icons/128x128/x2gosession.png"'.

x2go-DEBUG-../src/onmainwindow.cpp:6541> Setting focus.

x2go-INFO-8> "Starting connection to server: our domain:22"

x2go-DEBUG-../src/onmainwindow.cpp:2952> Starting new ssh connection to
server:"our domain":"22" krbLogin: false

x2go-DEBUG-../src/sshmasterconnection.cpp:175> SshMasterConnection, host
"our domain"; port 22; user "kudyba"; useproxy false; proxyserver "";
proxyport 22

x2go-DEBUG-../src/sshmasterconnection.cpp:248> Starting SSH connection
without Kerberos authentication.

x2go-DEBUG-../src/sshmasterconnection.cpp:252> SshMasterConnection,
instance SshMasterConnection(0x7fc3b0edda20) created.

x2go-DEBUG-../src/sshmasterconnection.cpp:520> SshMasterConnection,
instance SshMasterConnection(0x7fc3b0edda20) entering thread.

x2go-DEBUG-../src/sshmasterconnection.cpp:834> Session port before config
file parse: 22

x2go-DEBUG-../src/sshmasterconnection.cpp:844> Session port after config
file parse: 22

x2go-DEBUG-../src/sshmasterconnection.cpp:909> Session port before config
file parse (part 2): 22

x2go-DEBUG-../src/sshmasterconnection.cpp:919> Session port after config
file parse (part 2): 22

x2go-DEBUG-../src/sshmasterconnection.cpp:944> cserverAuth

x2go-DEBUG-../src/sshmasterconnection.cpp:985> state: 1


x2go-DEBUG-../src/sshmasterconnection.cpp:1268> Trying password mechanism
if available.


x2go-DEBUG-../src/sshmasterconnection.cpp:1272> Password mechanism
available. Continuing.


x2go-DEBUG-../src/sshmasterconnection.cpp:726> User authentication OK.

x2go-DEBUG-../src/sshmasterconnection.cpp:1764> LOGIN CHECK:"LOGIN OK

"

x2go-DEBUG-../src/sshmasterconnection.cpp:1767> don't have interaction

x2go-DEBUG-../src/sshmasterconnection.cpp:1800> LOOP FINISHED

x2go-DEBUG-../src/sshmasterconnection.cpp:1804> No interaction needed,
continue session

x2go-DEBUG-../src/sshmasterconnection.cpp:730> Login Check - OK

x2go-DEBUG-../src/onmainwindow.cpp:3058> SSH connection established.

x2go-DEBUG-../src/onmainwindow.cpp:3459> Continue normal X2Go session

x2go-DEBUG-../src/sshprocess.cpp:199> Executing remote command via
SshProcess object 0: "export HOSTNAME && x2golistsessions"

x2go-DEBUG-../src/sshprocess.cpp:213> this=SshProcess(0x7fc3b20da410)
Running masterCon->addChannelConnection(this, '
"455b5cc1-bd76-48f5-85bb-c91717fb47ae" ', ' "bash -l -c 'echo
"X2GODATABEGIN:455b5cc1-bd76-48f5-85bb-c91717fb47ae"; export
PATH="/usr/local/bin:/usr/bin:/bin";export TERM="dumb"; export HOSTNAME &&
x2golistsessions; echo "X2GODATAEND:455b5cc1-bd" ');

x2go-DEBUG-../src/sshmasterconnection.cpp:1866> Locking SSH channel
connection MUTEX.

x2go-DEBUG-../src/sshmasterconnection.cpp:1868> Passing new channel
connection object to channelConnections.

x2go-DEBUG-../src/sshmasterconnection.cpp:1870> Unlocking SSH channel
connection MUTEX.

x2go-DEBUG-../src/sshmasterconnection.cpp:2058> Creating new channel.


x2go-DEBUG-../src/sshmasterconnection.cpp:2075> New channel:0x7fc3b0f67440


x2go-DEBUG-../src/sshmasterconnection.cpp:2160> Executing remote: "bash -l
-c 'echo "X2GODATABEGIN:455b5cc1-bd76-48f5-85bb-c91717fb47ae"; export
PATH="/usr/local/bin:/usr/bin:/bin";export TERM="dumb"; export HOSTNAME &&
x2golistsessions; echo "X2GODATAEND:455b5cc1-bd76-48f5-85bb-c91717fb47ae";'"


x2go-DEBUG-../src/sshmasterconnection.cpp:2183> New exec channel created.


x2go-DEBUG-../src/sshmasterconnection.cpp:2232> EOF on channel
0x7fc3b0f67440; SshProcess object: 0

x2go-DEBUG-../src/sshmasterconnection.cpp:2355> EOF sent.

x2go-DEBUG-../src/sshmasterconnection.cpp:2359> Channel closed.

x2go-DEBUG-../src/sshprocess.cpp:526> SSH finished: raw output (stdout):
"X2GODATABEGIN:455b5cc1-bd76-48f5-85bb-c91717fb47ae

X2GODATAEND:455b5cc1-bd76-48f5-85bb-c91717fb47ae

"

x2go-DEBUG-../src/sshprocess.cpp:537> SSH finished: true - "" (0).

x2go-DEBUG-../src/onmainwindow.cpp:3927> ""

x2go-DEBUG-../src/onmainwindow.cpp:4487> Executing remote command:
"X2GODPI=72 x2gostartagent 800x600 adsl 16m-jpeg-9 unix-kde-depth_32 us
query 0 D XFCE both"

x2go-DEBUG-../src/sshprocess.cpp:199> Executing remote command via
SshProcess object 1: "X2GODPI=72 x2gostartagent 800x600 adsl 16m-jpeg-9
unix-kde-depth_32 us query 0 D XFCE both"

x2go-DEBUG-../src/sshprocess.cpp:213> this=SshProcess(0x7fc3b2055000)
Running masterCon->addChannelConnection(this, '
"7d75448a-fe94-4607-b475-80d7f9629e93" ', ' "bash -l -c 'echo
"X2GODATABEGIN:7d75448a-fe94-4607-b475-80d7f9629e93"; export
PATH="/usr/local/bin:/usr/bin:/bin";export TERM="dumb"; X2GODPI=72
x2gostartagent 800x600 adsl 16m-jpeg-9 unix-kde-depth_3" ');

x2go-DEBUG-../src/sshmasterconnection.cpp:1866> Locking SSH channel
connection MUTEX.

x2go-DEBUG-../src/sshmasterconnection.cpp:1868> Passing new channel
connection object to channelConnections.

x2go-DEBUG-../src/sshmasterconnection.cpp:1870> Unlocking SSH channel
connection MUTEX.

x2go-DEBUG-../src/sshmasterconnection.cpp:2058> Creating new channel.


x2go-DEBUG-../src/sshmasterconnection.cpp:2075> New channel:0x7fc3b20f5fb0


x2go-DEBUG-../src/sshmasterconnection.cpp:2160> Executing remote: "bash -l
-c 'echo "X2GODATABEGIN:7d75448a-fe94-4607-b475-80d7f9629e93"; export
PATH="/usr/local/bin:/usr/bin:/bin";export TERM="dumb"; X2GODPI=72
x2gostartagent 800x600 adsl 16m-jpeg-9 unix-kde-depth_32 us query 0 D XFCE
both; echo "X2GODATAEND:7d75448a-fe94-4607-b475-80d7f9629e93";'"


x2go-DEBUG-../src/sshmasterconnection.cpp:2183> New exec channel created.


x2go-DEBUG-../src/sshmasterconnection.cpp:2287> EOF on channel
0x7fc3b20f5fb0; SshProcess object: 1

x2go-DEBUG-../src/sshmasterconnection.cpp:2355> EOF sent.

x2go-DEBUG-../src/sshmasterconnection.cpp:2359> Channel closed.

x2go-DEBUG-../src/sshprocess.cpp:526> SSH finished: raw output (stdout):
"X2GODATABEGIN:7d75448a-fe94-4607-b475-80d7f9629e93

50

8e1465b1108ca7aa37f108de97ee7694

29109

kudyba-50-1513734261_stDXFCE_dp32

58571

58572

58573

X2GODATAEND:7d75448a-fe94-4607-b475-80d7f9629e93

"

x2go-DEBUG-../src/sshprocess.cpp:537> SSH finished: true - "50

8e1465b1108ca7aa37f108de97ee7694

29109

kudyba-50-1513734261_stDXFCE_dp32

58571

58572

58573

" (1).

x2go-DEBUG-../src/onmainwindow.cpp:5306> Agent output: "50

8e1465b1108ca7aa37f108de97ee7694

29109

kudyba-50-1513734261_stDXFCE_dp32

58571

58572

58573

"

x2go-DEBUG-../src/sshprocess.cpp:381> Starting tunnel via SshProcess object
2: "localhost":58571 -> "localhost":59571


x2go-DEBUG-../src/onmainwindow.cpp:5909> "Starting NX proxy, command:
"/Applications/x2goclient.app/Contents/exe/"nxproxy -S
nx/nx,options=/Users/rkudyba/.x2go/S-kudyba-50-1513734261_stDXFCE_dp32/options:50"

x2go-DEBUG-../src/sshprocess.cpp:157> Direct tunnel: waiting for
connections on "localhost":59571

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "

"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "N"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "XPROXY -
Version 3.5"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: ".0


Copyright (C) 2001, 2010 NoMachine.

See http://www.nomachine.com/ for more information.


Info: Proxy running in client mode with pid '"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "43808'.

Session: Starting session at '"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "T"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "u"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "e"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: " "

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "D"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "e"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "c"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: " 19
20:44:24 2017'.

"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "Info:
Connecting to remote host 'localhost:59571'.

"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "Info:
Connection to remote proxy 'localhost:59571' established.

"

x2go-DEBUG-../src/sshprocess.cpp:109> New TCP connection.

x2go-DEBUG-../src/sshprocess.cpp:114> New socket: 27

x2go-DEBUG-../src/sshmasterconnection.cpp:2058> Creating new channel.


x2go-DEBUG-../src/sshmasterconnection.cpp:2075> New channel:0x7fc3b0de99f0


x2go-DEBUG-../src/sshmasterconnection.cpp:2081> Forwarding parameters: from
remote ("localhost":58571) to local ("localhost":53987)

x2go-DEBUG-../src/sshmasterconnection.cpp:2118> Temporary session port
after config file parse: 58571

x2go-DEBUG-../src/sshmasterconnection.cpp:2122> Temporary session host
after config file parse: localhost

x2go-DEBUG-../src/sshmasterconnection.cpp:2152> New channel forwarded.


x2go-DEBUG-../src/sshmasterconnection.cpp:2312> "ssh_channel_write failed":
"Remote channel is closed"


x2go-DEBUG-../src/sshprocess.cpp:472> I/O error: "ssh_channel_write
failed."" - Remote channel is closed" (2).

x2go-DEBUG-../src/sshmasterconnection.cpp:2355> EOF sent.

x2go-DEBUG-../src/sshmasterconnection.cpp:2359> Channel closed.

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "E"

x2go-DEBUG-../src/onmainwindow.cpp:6381> Proxy wrote on stderr: "rror: The
remote NX proxy closed the connection.

Error: Failure negotiating the session in stage '7'.

Error: Wrong version or invalid session authentication cookie.

Session: Terminating session at 'Tue Dec 19 20:44:24 2017'.

Session: Session terminated at 'Tue Dec 19 20:44:24 2017'.

"

x2go-DEBUG-../src/onmainwindow.cpp:6234> Deleting Proxy.

x2go-DEBUG-../src/onmainwindow.cpp:6283> Waiting for proxy to exit.

x2go-DEBUG-../src/onmainwindow.cpp:6307> Checking exit status.

x2go-DEBUG-../src/sshprocess.cpp:199> Executing remote command via
SshProcess object 3: "x2gocmdexitmessage kudyba-50-1513734261_stDXFCE_dp32"

x2go-DEBUG-../src/sshprocess.cpp:213> this=SshProcess(0x7fc3b0f7f930)
Running masterCon->addChannelConnection(this, '
"cfa8f90d-7ff6-471b-97c0-88c649e13b29" ', ' "bash -l -c 'echo
"X2GODATABEGIN:cfa8f90d-7ff6-471b-97c0-88c649e13b29"; export
PATH="/usr/local/bin:/usr/bin:/bin";export TERM="dumb"; x2gocmdexitmessage
kudyba-50-1513734261_stDXFCE_dp32; echo "X2GODA" ');

x2go-DEBUG-../src/sshmasterconnection.cpp:1866> Locking SSH channel
connection MUTEX.

x2go-DEBUG-../src/sshmasterconnection.cpp:1868> Passing new channel
connection object to channelConnections.

x2go-DEBUG-../src/sshmasterconnection.cpp:1870> Unlocking SSH channel
connection MUTEX.

x2go-DEBUG-../src/sshmasterconnection.cpp:2058> Creating new channel.


x2go-DEBUG-../src/sshmasterconnection.cpp:2075> New channel:0x7fc3b20b0f10


x2go-DEBUG-../src/sshmasterconnection.cpp:2160> Executing remote: "bash -l
-c 'echo "X2GODATABEGIN:cfa8f90d-7ff6-471b-97c0-88c649e13b29"; export
PATH="/usr/local/bin:/usr/bin:/bin";export TERM="dumb"; x2gocmdexitmessage
kudyba-50-1513734261_stDXFCE_dp32; echo
"X2GODATAEND:cfa8f90d-7ff6-471b-97c0-88c649e13b29";'"


x2go-DEBUG-../src/sshmasterconnection.cpp:2168> "ssh_channel_open_session
failed": "Socket error: Unknown error: 316"


x2go-DEBUG-../src/onmainwindow.cpp:6364> Finished proxy.

x2go-DEBUG-../src/sshprocess.cpp:472> I/O error: "ssh_channel_open_session
failed."" - Socket error: Unknown error: 316" (3).

x2go-DEBUG-../src/onmainwindow.cpp:6541> Setting focus.



ps -auwx | grep x2go

kudyba 24707 0.0 0.0 120176 3220 ? Ss 20:38 0:00 bash -l -c
echo "X2GODATABEGIN:27cb07d2-e0db-4b73-a4df-9eb0c337c5dc"; export
PATH="/usr/local/bin:/usr/bin:/bin";export TERM="dumb"; x2goresume-session
kudyba-51-1513733787_stDMATE_dp32 800x600 adsl 16m-jpeg-9 us query 0 both;
echo "X2GODATAEND:27cb07d2-e0db-4b73-a4df-9eb0c337c5dc";

kudyba 24760 0.0 0.0 120048 3112 ? S 20:38 0:00 /bin/bash
/usr/bin/x2goresume-session kudyba-51-1513733787_stDMATE_dp32 800x600 adsl
16m-jpeg-9 us query 0 both

root 30840 0.0 0.2 180508 16960 ? S 20:46 0:00
/usr/bin/perl /usr/sbin/x2gocleansessions
Mihai Moldovan
2017-12-20 04:16:17 UTC
Permalink
Just started happening today. Something in the new build that could've caused
this? I see an old thread at
http://lists.x2go.org/pipermail/x2go-user/2013-July/001515.html not sure if it's
really the same issue though.
All RPM packages have been broken for the past few days due to the switch to
Arctica's version of nx-libs in the heuler repository.

I have been able to fix the issue a few hours ago.


Make sure to:

- dnf clean metadata
- dnf makecache
- dnf up --best --allowerasing



Mihai
Robert Kudyba
2017-12-20 04:19:14 UTC
Permalink
Post by Robert Kudyba
Post by Robert Kudyba
Just started happening today. Something in the new build that could've
caused
Post by Robert Kudyba
this? I see an old thread at
http://lists.x2go.org/pipermail/x2go-user/2013-July/001515.html not
sure if it's
Post by Robert Kudyba
really the same issue though.
All RPM packages have been broken for the past few days due to the switch to
Arctica's version of nx-libs in the heuler repository.
I have been able to fix the issue a few hours ago.
- dnf clean metadata
- dnf makecache
- dnf up --best --allowerasing
Indeed dnf clean all and dnf update seems to have fixed it.
Loading...