[X2Go-Dev] Error: Wrong version or invalid session authentication cookie/I/O error: ssh_channel_open_session failed. - Socket error: Unknown error: 316 in .git20171218.1453

Wed Dec 20 02:52:48 CET 2017

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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.x2go.org/pipermail/x2go-dev/attachments/20171219/2c0c8cf8/attachment-0001.html>