NX authentication error

Mon Jun 29 00:03:04 UTC 2009

I I set up a nxserver at remote PC (F10 2.6.27.25-170.2.72.fc10.i686),
followed all steps, shipped key from server to client. tried login
from client to sever as

ssh -i /usr/NX/share/keys/user.id_dsa.key nx at server
ssh -l USER1 server

all work.

when I login via nxclient, after pass steps Connected, download
session, it failed with errors:

NX> 203 NXSSH running with pid: 11935
NX> 285 Enabling check on switch command
NX> 285 Enabling skip of SSH config files
NX> 285 Setting the preferred NX options
NX> 200 Connected to address: xx.xx.xx.xx. on port: 22
NX> 202 Authenticating user: nx
NX> 208 Using auth method: publickey
HELLO NXSERVER - Version 3.3.0-22 - LFE
NX> 105 Hello NXCLIENT - Version 3.3.0
NX> 134 Accepted protocol: 3.3.0
NX> 105 Set shell_mode: shell
NX> 105 Set auth_mode: password
NX> 105 Login
NX> 101 User: USER1
NX> 102 Password: **********
NX> 103 Welcome to: localhost.localdomain user: USER1
NX> 105 Listsession --user="zhang" --status="suspended\054running"
--geometry="1280x1024x24+render" --type="unix-application"
NX> 127 Available sessions:

Display Type             Session ID                       Options
Depth Screen         Status      Session Name
------- ---------------- -------------------------------- --------
----- -------------- ----------- ------------------------------

NX> 148 Server capacity: not reached for user: USER1
NX> 105 Start session with: --rootless="1" --virtualdesktop="0"
--application="xterm" --link="adsl" --backingstore="1"
--encryption="1" --cache="16M" --images="64M" --shmem="1" --shpix="1"
--strict="0" --composite="1" --media="0" --session="neau"
--type="unix-application" --client="linux" --keyboard="pc105\057us"
--screeninfo="1280x1024x24+render"
NX> 502 ERROR: Public key authentication failed
NX> 502 ERROR: NX server was unable to login as user: USER1
NX> 502 ERROR: Please check that the account is enabled to login,
NX> 502 ERROR: the user's home directory, the directory ~/.ssh
NX> 502 ERROR: and the file ~/.ssh/authorized_keys2 have correct
NX> 502 ERROR: permissions setting according to the StrictModes
NX> 502 ERROR: of your SSHD configuration.
NX> 999 Bye.
NX> 280 Exiting on signal: 15

where is the problem?

thanks

Y

below is sshd message ai DEBUG2 level
Jun 29 07:44:37 localhost sshd[25855]: Accepted publickey for nx from
xx.xx.xx.xx port 51390 ssh2
Jun 29 07:44:37 localhost sshd[25855]: debug1: monitor_child_preauth:
nx has been authenticated by privileged process
Jun 29 07:44:37 localhost sshd[25855]: debug2: mac_setup: found hmac-md5
Jun 29 07:44:37 localhost sshd[25855]: debug2: mac_setup: found hmac-md5
Jun 29 07:44:37 localhost sshd[25855]: debug1: temporarily_use_uid:
489/483 (e=0/0)
Jun 29 07:44:37 localhost sshd[25855]: debug1: ssh_gssapi_storecreds:
Not a GSSAPI mechanism
Jun 29 07:44:37 localhost sshd[25855]: debug1: restore_uid: 0/0
Jun 29 07:44:37 localhost sshd[25855]: debug1: SELinux support disabled
Jun 29 07:44:37 localhost sshd[25855]: debug1: PAM: establishing credentials
Jun 29 07:44:37 localhost sshd[25855]: pam_unix(sshd:session): session
opened for user nx by (uid=0)
Jun 29 07:44:37 localhost sshd[25858]: debug1: PAM: establishing credentials
Jun 29 07:44:37 localhost sshd[25855]: User child is on pid 25858
Jun 29 07:44:38 localhost sshd[25858]: debug1: permanently_set_uid: 489/483
Jun 29 07:44:38 localhost sshd[25858]: debug2: set_newkeys: mode 0
Jun 29 07:44:38 localhost sshd[25858]: debug2: set_newkeys: mode 1
Jun 29 07:44:38 localhost sshd[25858]: debug1: Entering interactive
session for SSH2.
Jun 29 07:44:38 localhost sshd[25858]: debug2: fd 4 setting O_NONBLOCK
Jun 29 07:44:38 localhost sshd[25858]: debug2: fd 6 setting O_NONBLOCK
Jun 29 07:44:38 localhost sshd[25858]: debug1: server_init_dispatch_20
Jun 29 07:44:38 localhost sshd[25858]: debug1:
server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
Jun 29 07:44:38 localhost sshd[25858]: debug1: input_session_request
Jun 29 07:44:38 localhost sshd[25858]: debug1: channel 0: new [server-session]
Jun 29 07:44:38 localhost sshd[25858]: debug2: session_new: allocate
(allocated 0 max 10)
Jun 29 07:44:38 localhost sshd[25858]: debug1: session_new: session 0
Jun 29 07:44:38 localhost sshd[25858]: debug1: session_open: channel 0
Jun 29 07:44:38 localhost sshd[25858]: debug1: session_open: session
0: link with channel 0
Jun 29 07:44:38 localhost sshd[25858]: debug1:
server_input_channel_open: confirm session
Jun 29 07:44:38 localhost sshd[25858]: debug1:
server_input_channel_req: channel 0 request x11-req reply 0
Jun 29 07:44:38 localhost sshd[25858]: debug1: session_by_channel:
session 0 channel 0
Jun 29 07:44:38 localhost sshd[25858]: debug1:
session_input_channel_req: session 0 req x11-req
Jun 29 07:44:38 localhost sshd[25858]: debug2: bind port 6010: Address
already in use
Jun 29 07:44:38 localhost sshd[25858]: debug2: fd 7 setting O_NONBLOCK
Jun 29 07:44:38 localhost sshd[25858]: debug1: channel 1: new [X11
inet listener]
Jun 29 07:44:38 localhost sshd[25858]: debug2: fd 8 setting O_NONBLOCK
Jun 29 07:44:38 localhost sshd[25858]: debug1: channel 2: new [X11
inet listener]
Jun 29 07:44:38 localhost sshd[25858]: debug1:
server_input_channel_req: channel 0 request shell reply 0
Jun 29 07:44:38 localhost sshd[25858]: debug1: session_by_channel:
session 0 channel 0
Jun 29 07:44:38 localhost sshd[25858]: debug1:
session_input_channel_req: session 0 req shell
Jun 29 07:44:38 localhost sshd[25858]: debug1: Forced command (key
option) '/usr/NX/bin/nxserver --login'
Jun 29 07:44:38 localhost sshd[25858]: debug2: fd 3 setting TCP_NODELAY
Jun 29 07:44:38 localhost sshd[25858]: debug2: fd 11 setting O_NONBLOCK
Jun 29 07:44:38 localhost sshd[25858]: debug2: fd 10 setting O_NONBLOCK
Jun 29 07:44:38 localhost sshd[25858]: debug2: fd 13 setting O_NONBLOCK
Jun 29 07:44:39 localhost sshd[25901]: debug1: rexec start in 5 out 5
newsock 5 pipe 7 sock 8
Jun 29 07:44:39 localhost sshd[25852]: debug1: Forked child 25901.
Jun 29 07:44:39 localhost sshd[25901]: debug1: inetd sockets after dupping: 3, 3
Jun 29 07:44:39 localhost sshd[25901]: Connection from 127.0.0.1 port 60512
Jun 29 07:44:39 localhost sshd[25901]: debug1: Client protocol version
2.0; client software version OpenSSH_4.7
Jun 29 07:44:39 localhost sshd[25901]: debug1: match: OpenSSH_4.7 pat OpenSSH_4*
Jun 29 07:44:39 localhost sshd[25901]: debug1: Enabling compatibility
mode for protocol 2.0
Jun 29 07:44:39 localhost sshd[25901]: debug1: Local version string
SSH-2.0-OpenSSH_5.1
Jun 29 07:44:39 localhost sshd[25901]: debug2: fd 3 setting O_NONBLOCK
Jun 29 07:44:39 localhost sshd[25901]: debug2: Network child is on pid 25902
Jun 29 07:44:39 localhost sshd[25902]: debug1: permanently_set_uid: 74/74
Jun 29 07:44:39 localhost sshd[25902]: debug1: list_hostkey_types:
ssh-rsa,ssh-dss
Jun 29 07:44:39 localhost sshd[25902]: debug1: SSH2_MSG_KEXINIT sent
Jun 29 07:44:39 localhost sshd[25902]: debug1: SSH2_MSG_KEXINIT received
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
ssh-rsa,ssh-dss
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc at lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc at lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
none,zlib at openssh.com
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
none,zlib at openssh.com
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
first_kex_follows 0
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit: reserved 0
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
ssh-rsa,ssh-dss
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc at lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc at lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac-64 at openssh.com,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
none,zlib at openssh.com,zlib
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
none,zlib at openssh.com,zlib
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit:
first_kex_follows 0
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_parse_kexinit: reserved 0
Jun 29 07:44:39 localhost sshd[25902]: debug2: mac_setup: found hmac-md5
Jun 29 07:44:39 localhost sshd[25902]: debug1: kex: client->server
aes128-cbc hmac-md5 none
Jun 29 07:44:39 localhost sshd[25902]: debug2: mac_setup: found hmac-md5
Jun 29 07:44:39 localhost sshd[25902]: debug1: kex: server->client
aes128-cbc hmac-md5 none
Jun 29 07:44:39 localhost sshd[25902]: debug1:
SSH2_MSG_KEX_DH_GEX_REQUEST received
Jun 29 07:44:39 localhost sshd[25902]: debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
Jun 29 07:44:39 localhost sshd[25902]: debug2: dh_gen_key: priv key
bits set: 119/256
Jun 29 07:44:39 localhost sshd[25902]: debug2: bits set: 501/1024
Jun 29 07:44:39 localhost sshd[25902]: debug1: expecting
SSH2_MSG_KEX_DH_GEX_INIT
Jun 29 07:44:39 localhost sshd[25901]: debug2: monitor_read: 0 used
once, disabling now
Jun 29 07:44:39 localhost sshd[25902]: debug2: bits set: 511/1024
Jun 29 07:44:39 localhost sshd[25902]: debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
Jun 29 07:44:39 localhost sshd[25901]: debug2: monitor_read: 5 used
once, disabling now
Jun 29 07:44:39 localhost sshd[25902]: debug2: kex_derive_keys
Jun 29 07:44:39 localhost sshd[25902]: debug2: set_newkeys: mode 1
Jun 29 07:44:39 localhost sshd[25902]: debug1: SSH2_MSG_NEWKEYS sent
Jun 29 07:44:39 localhost sshd[25902]: debug1: expecting SSH2_MSG_NEWKEYS
Jun 29 07:44:39 localhost sshd[25902]: debug2: set_newkeys: mode 0
Jun 29 07:44:39 localhost sshd[25902]: debug1: SSH2_MSG_NEWKEYS received
Jun 29 07:44:39 localhost sshd[25902]: debug1: KEX done
Jun 29 07:44:39 localhost sshd[25902]: debug1: userauth-request for
user USER1 service ssh-connection method none
Jun 29 07:44:39 localhost sshd[25902]: debug1: attempt 0 failures 0
Jun 29 07:44:39 localhost sshd[25901]: debug2: parse_server_config:
config reprocess config len 696
Jun 29 07:44:39 localhost sshd[25901]: debug2: monitor_read: 7 used
once, disabling now
Jun 29 07:44:39 localhost sshd[25902]: debug2: input_userauth_request:
setting up authctxt for USER1
Jun 29 07:44:39 localhost sshd[25901]: debug1: PAM: initializing for "USER1"
Jun 29 07:44:39 localhost sshd[25901]: debug1: PAM: setting PAM_RHOST
to "localhost.localdomain"
Jun 29 07:44:39 localhost sshd[25901]: debug1: PAM: setting PAM_TTY to "ssh"
Jun 29 07:44:39 localhost sshd[25901]: debug2: monitor_read: 46 used
once, disabling now
Jun 29 07:44:39 localhost sshd[25902]: debug2: input_userauth_request:
try method none
Jun 29 07:44:39 localhost sshd[25901]: debug2: monitor_read: 3 used
once, disabling now
Jun 29 07:44:39 localhost sshd[25901]: debug2: monitor_read: 4 used
once, disabling now
Jun 29 07:44:39 localhost sshd[25902]: debug1: userauth-request for
user USER1 service ssh-connection method password
Jun 29 07:44:39 localhost sshd[25902]: debug1: attempt 1 failures 0
Jun 29 07:44:39 localhost sshd[25902]: debug2: input_userauth_request:
try method password
Jun 29 07:44:39 localhost sshd[25901]: debug1: PAM: password
authentication accepted for USER1
Jun 29 07:44:39 localhost sshd[25901]: debug1: do_pam_account: called
Jun 29 07:44:39 localhost sshd[25901]: Accepted password for USER1
from 127.0.0.1 port 60512 ssh2
Jun 29 07:44:39 localhost sshd[25901]: debug1: monitor_child_preauth:
USER1 has been authenticated by privileged process
Jun 29 07:44:39 localhost sshd[25901]: debug2: mac_setup: found hmac-md5
Jun 29 07:44:39 localhost sshd[25901]: debug2: mac_setup: found hmac-md5
Jun 29 07:44:39 localhost sshd[25901]: debug1: temporarily_use_uid:
503/504 (e=0/0)
Jun 29 07:44:39 localhost sshd[25901]: debug1: ssh_gssapi_storecreds:
Not a GSSAPI mechanism
Jun 29 07:44:39 localhost sshd[25901]: debug1: restore_uid: 0/0
Jun 29 07:44:39 localhost sshd[25901]: debug1: SELinux support disabled
Jun 29 07:44:39 localhost sshd[25901]: debug1: PAM: establishing credentials
Jun 29 07:44:39 localhost sshd[25901]: pam_unix(sshd:session): session
opened for user USER1 by (uid=0)
Jun 29 07:44:39 localhost sshd[25901]: User child is on pid 25903
Jun 29 07:44:39 localhost sshd[25903]: debug1: PAM: establishing credentials
Jun 29 07:44:39 localhost sshd[25903]: debug1: permanently_set_uid: 503/504
Jun 29 07:44:39 localhost sshd[25903]: debug2: set_newkeys: mode 0
Jun 29 07:44:39 localhost sshd[25903]: debug2: set_newkeys: mode 1
Jun 29 07:44:39 localhost sshd[25903]: debug1: Entering interactive
session for SSH2.
Jun 29 07:44:39 localhost sshd[25903]: debug2: fd 4 setting O_NONBLOCK
Jun 29 07:44:39 localhost sshd[25903]: debug2: fd 6 setting O_NONBLOCK
Jun 29 07:44:39 localhost sshd[25903]: debug1: server_init_dispatch_20
Jun 29 07:44:39 localhost sshd[25903]: Connection closed by 127.0.0.1
Jun 29 07:44:39 localhost sshd[25903]: debug1: do_cleanup
Jun 29 07:44:39 localhost sshd[25903]: Transferred: sent 1768,
received 1184 bytes
Jun 29 07:44:39 localhost sshd[25903]: Closing connection to 127.0.0.1
port 60512
Jun 29 07:44:39 localhost sshd[25901]: debug1: PAM: cleanup
Jun 29 07:44:39 localhost sshd[25901]: debug1: PAM: deleting credentials
Jun 29 07:44:39 localhost sshd[25901]: debug1: PAM: closing session
Jun 29 07:44:39 localhost sshd[25901]: pam_unix(sshd:session): session
closed for user USER1
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: read<=0 rfd 11 len 0
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: read failed
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: close_read
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: input open -> drain
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: ibuf_empty
delayed efd 13/(0)
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: read 0 from efd 13
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: closing read-efd 13
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: ibuf empty
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: send eof
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: input drain -> closed
Jun 29 07:44:41 localhost sshd[25858]: debug1: Received SIGCHLD.
Jun 29 07:44:41 localhost sshd[25858]: debug1: session_by_pid: pid 25859
Jun 29 07:44:41 localhost sshd[25858]: debug1: session_exit_message:
session 0 channel 0 pid 25859
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: request
exit-status confirm 0
Jun 29 07:44:41 localhost sshd[25858]: debug1: session_exit_message:
release channel 0
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: write failed
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: close_write
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: send eow
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: output open -> closed
Jun 29 07:44:41 localhost sshd[25858]: debug2: channel 0: send close
Jun 29 07:44:41 localhost sshd[25858]: debug2: notify_done: reading
Jun 29 07:44:41 localhost sshd[25858]: Connection closed by xx.xx.xx.xx
Jun 29 07:44:41 localhost sshd[25858]: debug1: channel 0: free:
server-session, nchannels 3
Jun 29 07:44:41 localhost sshd[25858]: debug1: channel 1: free: X11
inet listener, nchannels 2
Jun 29 07:44:41 localhost sshd[25858]: debug1: channel 2: free: X11
inet listener, nchannels 1
Jun 29 07:44:41 localhost sshd[25858]: debug1: session_close: session 0 pid 0
Jun 29 07:44:41 localhost sshd[25858]: debug1: do_cleanup
Jun 29 07:44:41 localhost sshd[25858]: Transferred: sent 3832,
received 2496 bytes
Jun 29 07:44:41 localhost sshd[25858]: Closing connection to
xx.xx.xx.xx port 51390
Jun 29 07:44:41 localhost sshd[25855]: debug1: PAM: cleanup
Jun 29 07:44:41 localhost sshd[25855]: debug1: PAM: deleting credentials
Jun 29 07:44:42 localhost sshd[25855]: debug1: PAM: closing session
Jun 29 07:44:42 localhost sshd[25855]: pam_unix(sshd:session): session
closed for user nx