cancel
Showing results for 
Search instead for 
Did you mean: 

NBU java admin console Unable to login status

SteveLaw
Level 5

Hi,

Netbackup Java Console is giving me error "Status: 517, cannot connect to the NB-Java user service via VNETD on [master server] on port 13724". 

This has been working for some time, error seemed to coincide with routine windows security updates that were installed recently, I've removed those updates but still get the same message. 

I can telnet between this server and the master on port 13724. Can anyone suggest what the problem might be?

Thanks 

1 ACCEPTED SOLUTION

Accepted Solutions

Mike_Gavrilov
Moderator
Moderator
Partner    VIP    Accredited Certified

 

09:54:05.575 [4880.5660] <8> vnet_pop_byte: [vnet.c:194] errno 0 0x0
09:54:05.575 [4880.5660] <2> vnet_pop_byte: vnet.c.196: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <2> vnet_pop_string: vnet.c.276: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <2> vnet_pop_signed: vnet.c.319: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <2> vnet_version_accept: .\vnetd.c.1116: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <8> ProcessRequests: [.\vnetd.c:684] version_accept failed 9 0x9

this block reminds the problem:

https://www.veritas.com/support/en_US/article.000108081

It might be because of connect options on the master server? Do you have a firewall between machine with console and master? You can try this:

https://www.veritas.com/support/en_US/article.TECH42653 or you can try to change master server'sconnect options but it might lead to problem with backups. 

 

 

View solution in original post

12 REPLIES 12

SteveLaw
Level 5

PS: Both servers are running NBU 7.6.1.2. 

Master is swm009, section from the bpjava-msvc log on the master:

15:18:22.268 [8084.3552] <16> session_dispatch: Request count = 0 tag = 510
15:18:22.268 [8084.3552] <2> populateCertificatePath: Certificate to be used for SSL [E:\Program Files\Veritas\NetBackup\var\vxss\credentials\swm009.corpadds.net]
15:18:22.268 [8084.3552] <4> command_SECURE_CHANNEL_INIT: Using certificate [E:\Program Files\Veritas\NetBackup\var\vxss\credentials\swm009.corpadds.net] and Responding SECURE_CHANNEL_PROCEED.
15:18:22.456 [8084.3552] <4> session_secure_lookup: Initiating SSL Accept
15:18:22.456 [8084.3552] <2> populateCertificatePath: Certificate to be used for SSL [E:\Program Files\Veritas\NetBackup\var\vxss\credentials\swm009.corpadds.net]
15:18:22.487 [8084.3552] <4> tls_vxss_accept: io.c.3414: SSL Channel established for fd[388]
15:18:22.487 [8084.3552] <4> session_secure_lookup: SSL Connection Accepted!
15:18:22.487 [8084.3552] <16> session_dispatch: Request count = 1 tag = 118
15:18:22.893 [8084.3552] <16> session_dispatch: Request count = 2 tag = 101
15:18:23.252 [8084.3552] <16> command_LOGON_TO_MSERVER: putenv(BPJAVA_MASTER_IPC_STRING=) failed
15:18:23.252 [8084.3552] <2> generate_session_cert: Using user name as [corpadds\slaw] and hostname as [swm009.corpadds.net]
15:18:24.440 [8084.3552] <2> export_session_credentials_to_chld: Length of message that would be exported [2377]
15:18:24.440 [8084.3552] <2> export_session_credentials_to_chld: Written buffer length [4]
15:18:24.440 [8084.3552] <2> export_session_credentials_to_chld: No.of bytes written [2377]
15:18:24.440 [8084.3552] <2> export_session_credentials_to_chld: Written token length [4]
15:18:24.440 [8084.3552] <2> export_session_credentials_to_chld: Written token [XXX]
15:18:24.440 [8084.3552] <2> acquireTerminationToken: hJobToken bpjava-msvc_6928 = 000000000000052C for pid = 6928
15:18:24.440 [8084.3552] <2> setUserServerTokens: server index = 0, hJobToken = 000000000000052C for pid = 6928
15:18:24.456 [8084.3552] <16> fillReadBuff: ReadFile failed readStat = 109 = The pipe has been ended. , pLength = 0


nbutech
Level 6
Accredited Certified

Check the  jbp.xxxxxxxxxxxxxxxx.log file and see if permission or other errors for bpauthorize

Mike_Gavrilov
Moderator
Moderator
Partner    VIP    Accredited Certified
Have you already checked if VNETD_PORT entry in the install_path\java\setconf.bat is correct?

Is it possible that another app is listening the port instead of VNETD?

Hi, thanks for your input.

setconf.bat has SET VNETD_PORT=13724

I can telnet to the Java console server from the master on 13724, using short hostname, fqdn and ip address. 

As below on the server running the Java console, I can find the process listening on 13724, then tasklist shows that process is vnetd.exe: 

E:\Program Files\Veritas\NetBackup\bin>netstat -a -o -n | find /i "13724"
TCP 0.0.0.0:13724 0.0.0.0:0 LISTENING 2512

E:\Program Files\Veritas\NetBackup\bin>tasklist | find /i "2512"
vnetd.exe 2512 Services 0 8,052 K

 

 

This is what I get in the jbp.*.log on the Java console server ukdcsitdb01 (53.202.170.125) when I attempt a login (swm009 on 53.202.170.149 is the master) : 

java version "1.7.0_55"
Java(TM) SE Runtime Environment (build 1.7.0_55-b13)
Java HotSpot(TM) 64-Bit Server VM (build 24.55-b03, mixed mode)

ServerInterface:setDebugLevel:262144
BpjavaLoginModule:Setting ServerRequest, debugLevel:262144
BpjavaLoginModule:connectServer:[corpadds\slaw][swm009.corpadds.net][0]
From Logon, Connecting to vnetd service over PBX port = 1556, authService is true
Acknowledgement from PBX1
Mutual Auth : true

Protocol Code: 101
Status: 0
Time Taken: 3238ms
Error Msg:
Server Locale: en_GB
TO[0]: corpadds\slaw
TO[1]: swm009.corpadds.net
TO[2]: en_GB
TO[3]: XXXX
TO[4]: auth.conf
TO[5]: 760000 IPC
FROM[0]: -1 760000 true 7.6.1.2 11C40CB9B3235ABF15C67BC77F06EB72328E4286 883B219E57B1F9AE5D926D32226585AB
FROM[1]: 57113
FROM[2]: isAdminUser unknown vxssMode 2 useAuthentication 0
FROM[3]: corpadds\slaw ADMIN=ALL JBP=ALL
FROM[4]: * ADMIN=JBP JBP=ENDUSER+BU+ARC
Aux data: null

Acknowledgement from PBX1
Mutual Auth : true
vrts.vss.sdk.at.exception.VRTSAtException:
at vrts.vss.sdk.at.lib.core.Authenticator.atSecConnConnectEx(Native Method)
at vrts.vss.sdk.at.lib.core.Authenticator.vrtsAtSecConnConnectEx(Authenticator.java:2733)
at vrts.vss.sdk.at.lib.core.Authenticator.vrtsAtSecConnConnectEx(Authenticator.java:2708)
at vrts.shared.server.VxATSocket.sslConnect(VxATSocket.java:337)
at vrts.shared.server.ServerInterface.secureConnect(ServerInterface.java:1142)
at vrts.shared.server.ServerInterface.connectToServiceViaVNETD(ServerInterface.java:1237)
at vrts.shared.server.ServerInterface.executeRun(ServerInterface.java:2565)
at vrts.shared.server.ServerInterface.run(ServerInterface.java:2290)
Acknowledgement from PBX1
ServerInterface:Logon - Initial host:null, Current host:swm009.corpadds.net, PBX port:1556
Can not connect to the NB-Java authentication service on swm009.corpadds.net on port 1556. Exception:
java.net.ConnectException: Connection to user service via VNETD is unsuccessful - status: 18 .
Could not connect to vnetd over PBX. Trying connection directly to vnetd service on port = 13724
ServerInterface:run: java.net.ConnectException: Connection to user service via VNETD is unsuccessful - status: 18 .
ServerInterface:run - Initial host=null:Current host=swm009.corpadds.net:MS port=0:VNETD=13724:m_intPort=-1:localPort=0:range use=false
Can not connect to the NB-Java user service via VNETD on swm009.corpadds.net on port 13724.
Exception:java.net.ConnectException: Connection to user service via VNETD is unsuccessful - status: 18 .
(SR-0)Logon:
Protocol Code: 101
Status: 517
Time Taken: 3238ms
Error Msg: Can not connect to the NB-Java user service via VNETD on swm009.corpadds.net on port 13724. Check the log file for more details.
Server Locale: en_GB
TO[0]: corpadds\slaw
TO[1]: swm009.corpadds.net
TO[2]: en_GB
TO[3]: XXXX
TO[4]: auth.conf
TO[5]: 760000 IPC
FROM[0]: -1 760000 true 7.6.1.2 11C40CB9B3235ABF15C67BC77F06EB72328E4286 883B219E57B1F9AE5D926D32226585AB
FROM[1]: 57113
FROM[2]: isAdminUser unknown vxssMode 2 useAuthentication 0
FROM[3]: corpadds\slaw ADMIN=ALL JBP=ALL
FROM[4]: * ADMIN=JBP JBP=ENDUSER+BU+ARC
Aux data: null

I tested and cannot telnet from the java console server to the master on port 1566. Actually on testing I can't telnet to or from the master on port 1566 from any of my media servers!! The PBX service is running on all servers. 

Is this normal? Beginning to suspect that the network team have blocked this port on the firewalls. But surely that would cause problems all over our Netbackup infrastructure?!!? 

Mike_Gavrilov
Moderator
Moderator
Partner    VIP    Accredited Certified


I tested and cannot telnet from the java console server to the master on port 1566. Actually on testing I can't telnet to or from the master on port 1566 from any of my media servers!! The PBX service is running on all servers. 

Is this normal? 

No, PBX port must be open.  Please  check  the Guide https://www.veritas.com/support/en_US/article.DOC8605 on page 11

 

ServerInterface:Logon - Initial host:null, Current host:swm009.corpadds.net, PBX port:1556
Can not connect to the NB-Java authentication service on swm009.corpadds.net on port 1556. 

AH no that was me being stupid - it is Monday morning... I was checking port 1566 but of course PBX uses 1556. When I check telnet on 1566 it all checks out: I can telnet from the master to the java console and vice versa on port 1556, using fqdn, short hostname and ip address. So PBX comms is not the problem. From the master I can see PBX 1556 active connections are established with the java console server: 

C:\>netstat -a -o -n | find /i "53.202.170.125"
TCP 53.202.170.149:1556 53.202.170.125:49253 ESTABLISHED 2484
TCP 53.202.170.149:1556 53.202.170.125:49315 ESTABLISHED 2484
TCP 53.202.170.149:1556 53.202.170.125:49347 ESTABLISHED 2484
TCP 53.202.170.149:1556 53.202.170.125:49349 ESTABLISHED 2484
TCP 53.202.170.149:1556 53.202.170.125:49570 ESTABLISHED 2484
TCP 53.202.170.149:1556 53.202.170.125:55744 ESTABLISHED 2484
TCP 53.202.170.149:1556 53.202.170.125:55746 ESTABLISHED 2484

C:\>tasklist | find /i "2484"
pbx_exchange.exe 2484 Services 0 8,756 K

So why is that log saying it can't connect???










Mike_Gavrilov
Moderator
Moderator
Partner    VIP    Accredited Certified

Could you share vnetd logs? :)

Hi, here's the latest log, I can turn up the debug and generate a new one if necessary:

00:00:00.931 [3664.4856] <2> setup_debug_log: switched debug log file for vnetd
00:25:26.256 [3664.4856] <2> vnet_pbxAcceptSocket: Accepted sock[364] from 53.202.170.149:64721
00:25:26.305 [352.4404] <2> setup_debug_log: switched debug log file for vnetd
00:25:26.308 [352.4404] <4> main: VERBOSE=0, VNETD VERBOSE=0 Timestamp=1476115773
00:25:26.308 [352.4404] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\vnetd.exe -standalone
00:25:26.410 [352.4404] <8> ProcessRequests: [.\vnetd.c:679] msg VNETD ACCEPT FROM 53.202.170.149.64721 TO 53.202.170.125.1556 fd = 364
00:25:26.410 [352.4404] <8> vnet_version_accept: [.\vnetd.c:1136] *actual_version 11 0xb
00:25:26.606 [352.4404] <8> ProcessRequests: [.\vnetd.c:762] msg Request VN_REQUEST_CONNECT_FORWARD_SOCKET(10)
00:25:26.640 [352.4404] <8> process_connect_forward_socket: [.\vnetd.c:2014] ipc_string 54751
00:25:27.206 [352.4404] <8> ProcessRequests: [.\vnetd.c:764] status 0 0x0
00:25:28.111 [3664.4856] <2> vnet_pbxAcceptSocket: Accepted sock[364] from 53.202.170.149:64736
00:25:28.146 [5996.908] <2> setup_debug_log: switched debug log file for vnetd
00:25:28.152 [5996.908] <4> main: VERBOSE=0, VNETD VERBOSE=0 Timestamp=1476115773
00:25:28.152 [5996.908] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\vnetd.exe -standalone
00:25:28.154 [5996.908] <8> ProcessRequests: [.\vnetd.c:679] msg VNETD ACCEPT FROM 53.202.170.149.64736 TO 53.202.170.125.1556 fd = 364
00:25:28.155 [5996.908] <8> vnet_version_accept: [.\vnetd.c:1136] *actual_version 11 0xb
00:25:28.358 [5996.908] <8> ProcessRequests: [.\vnetd.c:762] msg Request VN_REQUEST_CONNECT_FORWARD_SOCKET(10)
00:25:28.360 [5996.908] <8> process_connect_forward_socket: [.\vnetd.c:2014] ipc_string 54754
00:25:28.841 [5996.908] <8> ProcessRequests: [.\vnetd.c:764] status 0 0x0
09:27:10.183 [5732.2800] <2> setup_debug_log: switched debug log file for vnetd
09:27:10.188 [5732.2800] <4> main: VERBOSE=0, VNETD VERBOSE=0 Timestamp=1476115773
09:27:10.188 [5732.2800] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\vnetd.exe -standalone
09:27:10.194 [5732.2800] <8> ProcessRequests: [.\vnetd.c:679] msg VNETD ACCEPT FROM 53.202.170.149.56689 TO 53.202.170.125.13724 fd = 364
09:27:14.717 [5732.2800] <8> vnet_pop_byte: [vnet.c:194] errno 0 0x0
09:27:14.717 [5732.2800] <2> vnet_pop_byte: vnet.c.196: 0: Function failed: 9 0x00000009
09:27:14.718 [5732.2800] <2> vnet_pop_string: vnet.c.276: 0: Function failed: 9 0x00000009
09:27:14.718 [5732.2800] <2> vnet_pop_signed: vnet.c.319: 0: Function failed: 9 0x00000009
09:27:14.718 [5732.2800] <2> vnet_version_accept: .\vnetd.c.1116: 0: Function failed: 9 0x00000009
09:27:14.718 [5732.2800] <8> ProcessRequests: [.\vnetd.c:684] version_accept failed 9 0x9
09:27:14.718 [5732.2800] <8> main: [.\vnetd.c:417] ProcessRequests failed, retval=9
09:27:42.644 [6008.2488] <2> setup_debug_log: switched debug log file for vnetd
09:27:42.649 [6008.2488] <4> main: VERBOSE=0, VNETD VERBOSE=0 Timestamp=1476115773
09:27:42.649 [6008.2488] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\vnetd.exe -standalone
09:27:42.653 [6008.2488] <8> ProcessRequests: [.\vnetd.c:679] msg VNETD ACCEPT FROM 53.202.170.149.56732 TO 53.202.170.125.13724 fd = 364
09:27:46.277 [6008.2488] <8> vnet_pop_byte: [vnet.c:194] errno 0 0x0
09:27:46.278 [6008.2488] <2> vnet_pop_byte: vnet.c.196: 0: Function failed: 9 0x00000009
09:27:46.278 [6008.2488] <2> vnet_pop_string: vnet.c.276: 0: Function failed: 9 0x00000009
09:27:46.278 [6008.2488] <2> vnet_pop_signed: vnet.c.319: 0: Function failed: 9 0x00000009
09:27:46.278 [6008.2488] <2> vnet_version_accept: .\vnetd.c.1116: 0: Function failed: 9 0x00000009
09:27:46.278 [6008.2488] <8> ProcessRequests: [.\vnetd.c:684] version_accept failed 9 0x9
09:27:46.278 [6008.2488] <8> main: [.\vnetd.c:417] ProcessRequests failed, retval=9
09:28:06.067 [4688.4640] <2> setup_debug_log: switched debug log file for vnetd
09:28:06.070 [4688.4640] <4> main: VERBOSE=0, VNETD VERBOSE=0 Timestamp=1476115773
09:28:06.070 [4688.4640] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\vnetd.exe -standalone
09:28:06.073 [4688.4640] <8> ProcessRequests: [.\vnetd.c:679] msg VNETD ACCEPT FROM 53.202.170.149.56793 TO 53.202.170.125.13724 fd = 364
09:28:10.036 [4688.4640] <8> vnet_pop_byte: [vnet.c:194] errno 0 0x0
09:28:10.036 [4688.4640] <2> vnet_pop_byte: vnet.c.196: 0: Function failed: 9 0x00000009
09:28:10.036 [4688.4640] <2> vnet_pop_string: vnet.c.276: 0: Function failed: 9 0x00000009
09:28:10.036 [4688.4640] <2> vnet_pop_signed: vnet.c.319: 0: Function failed: 9 0x00000009
09:28:10.036 [4688.4640] <2> vnet_version_accept: .\vnetd.c.1116: 0: Function failed: 9 0x00000009
09:28:10.036 [4688.4640] <8> ProcessRequests: [.\vnetd.c:684] version_accept failed 9 0x9
09:28:10.036 [4688.4640] <8> main: [.\vnetd.c:417] ProcessRequests failed, retval=9
09:54:01.547 [4880.5660] <2> setup_debug_log: switched debug log file for vnetd
09:54:01.550 [4880.5660] <4> main: VERBOSE=0, VNETD VERBOSE=0 Timestamp=1476115773
09:54:01.550 [4880.5660] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\vnetd.exe -standalone
09:54:01.553 [4880.5660] <8> ProcessRequests: [.\vnetd.c:679] msg VNETD ACCEPT FROM 53.202.170.149.60229 TO 53.202.170.125.13724 fd = 364
09:54:05.575 [4880.5660] <8> vnet_pop_byte: [vnet.c:194] errno 0 0x0
09:54:05.575 [4880.5660] <2> vnet_pop_byte: vnet.c.196: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <2> vnet_pop_string: vnet.c.276: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <2> vnet_pop_signed: vnet.c.319: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <2> vnet_version_accept: .\vnetd.c.1116: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <8> ProcessRequests: [.\vnetd.c:684] version_accept failed 9 0x9
09:54:05.575 [4880.5660] <8> main: [.\vnetd.c:417] ProcessRequests failed, retval=9
10:31:01.864 [3664.4856] <8> main: [.\vnetd.c:557] got terminate request 0 0x0
10:31:02.008 [3664.4856] <4> main: EXIT status = 0
10:32:18.509 [2064.2068] <2> setup_debug_log: switched debug log file for vnetd
10:32:18.512 [2064.2068] <4> main: VERBOSE=0, VNETD VERBOSE=0 Timestamp=1476115773
10:32:18.512 [2064.2068] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\vnetd.exe -standalone
10:32:18.515 [2064.2068] <2> setup_debug_log: switching debug log file for vnetd
10:32:18.515 [2064.2068] <2> setup_debug_log: switched debug log file for vnetd
10:32:18.532 [2064.2068] <2> daemon_startup_listeners: 4 listening for legacy service vnetd
10:32:18.533 [2064.2068] <2> vnet_registerPBXServer: ../../libvlibs/vnet_pbx.c.121: pbxRegisterEx successful at 53.202.170.125:5126/vnetd, returns with 0 alt_addrs
11:24:27.649 [2064.2068] <8> main: [.\vnetd.c:557] got terminate request 0 0x0
11:24:27.675 [2064.2068] <4> main: EXIT status = 0
11:25:30.886 [2236.2240] <2> setup_debug_log: switched debug log file for vnetd
11:25:30.889 [2236.2240] <4> main: VERBOSE=0, VNETD VERBOSE=0 Timestamp=1476115773
11:25:30.889 [2236.2240] <2> logparams: C:\Program Files\Veritas\NetBackup\bin\vnetd.exe -standalone
11:25:30.891 [2236.2240] <2> setup_debug_log: switching debug log file for vnetd
11:25:30.891 [2236.2240] <2> setup_debug_log: switched debug log file for vnetd
11:25:30.898 [2236.2240] <8> cache_item_to_file: [vnet_addrinfo.c:6434] rename() failed 13 0xd
11:25:30.898 [2236.2240] <8> vnet_cached_getaddrinfo_and_update: [vnet_addrinfo.c:1705] cache_item_to_file() failed 0 0x0
11:25:30.901 [2236.2240] <2> daemon_startup_listeners: 4 listening for legacy service vnetd
11:25:30.903 [2236.2240] <2> vnet_registerPBXServer: ../../libvlibs/vnet_pbx.c.121: pbxRegisterEx successful at 53.202.170.125:5126/vnetd, returns with 0 alt_addrs
 


Mike_Gavrilov
Moderator
Moderator
Partner    VIP    Accredited Certified

 

09:54:05.575 [4880.5660] <8> vnet_pop_byte: [vnet.c:194] errno 0 0x0
09:54:05.575 [4880.5660] <2> vnet_pop_byte: vnet.c.196: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <2> vnet_pop_string: vnet.c.276: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <2> vnet_pop_signed: vnet.c.319: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <2> vnet_version_accept: .\vnetd.c.1116: 0: Function failed: 9 0x00000009
09:54:05.575 [4880.5660] <8> ProcessRequests: [.\vnetd.c:684] version_accept failed 9 0x9

this block reminds the problem:

https://www.veritas.com/support/en_US/article.000108081

It might be because of connect options on the master server? Do you have a firewall between machine with console and master? You can try this:

https://www.veritas.com/support/en_US/article.TECH42653 or you can try to change master server'sconnect options but it might lead to problem with backups. 

 

 

I uninstalled all Netbackup components on this server - the NBU client and the Java console - and reinstalled and now it's working [shrug]. 

Thanks for everyone's input. Looks like this was just some kind of corruption.