AuthTokenHash matched, but couldn't get the userid

[craigr]

I have one employee today who can't log into Vault from her machine. The server log says "AuthTokenHash matched, but couldn't get the userid" and that's all. She sees a message "unable to connect to (url). No server was found at the specified URL. Please verify your network settings using the options dialog under the tools menu in the vault GUI client." The URL is correct and is what it always is.

I can log in as her on my machine. She can log into the web client from her machine. We're running Vault server 5.1.1.19215. Client is the same.

Any hints as to where we can look for this problem?

Craig

[lbauer]

Can you log in as you from her machine?

Was she able to login before -- is this a new problem?

Is there a client log? It's called Vaultguiclient.txt and would be in the user's temp directory, %temp%.

[craigr]

Good suggestion… no, I can't log in as me from her machine. I get the same error.

She has never had trouble logging in before. This is new this morning.

I couldn't find a log of any kind in C:\temp or C:\Windows\Temp. I couldn't find any way to turn logging on or off in the client.

Craig

[lbauer]

If neither of you can connect, it indicates some sort of network problem.

Is the Vault Client going through a a proxy?

Have firewall settings on that machine changed? Sometimes Windows updates will do that.

To enable client-side logging in the GUI Client open the Vault GUI Client and hold down the following keys on your keyboard:

Control-Alt Shift F12

The Vault Client log is called vaultguiclient.txt and is the user's temp directory on the client machine.

[craigr]

There's no proxy. No known firewall changes.

There are 4 other machines on this same wireless network and none of the others are having problems connecting to Vault.

Turns out the log was already turned on; we just weren't looking in the right place. Here's what we see in the log when we try to log in (I changed the URL in the error messages so you won't find a Vault server there either):

3/26/2014 2:11:12 PM <generic>: [Main:6960] Emergency logging enabled in Windows Forms client
3/26/2014 2:11:40 PM <busy>: [GUIClientWorkerThread:7128] Setting GUI to busy from ConnectToServer
3/26/2014 2:11:45 PM <eventengine>: [GUIClientWorkerThread:7128] Event fired: VaultClientOperationsLib.ConnectionStateChangedEvent
3/26/2014 2:11:45 PM <statussearch>: [Main:6960] Connection state changed from Unconnected to Connecting
3/26/2014 2:11:45 PM <connection>: [GUIClientWorkerThread:7128] Login started.
3/26/2014 2:11:45 PM <emailview>: [Main:6960] Connection state changed from Unconnected to Connecting
3/26/2014 2:11:47 PM <generic>: [GUIClientWorkerThread:7128] [System.Net.Sockets.SocketException: No connection could be made because the target machine actively refused it 127.0.0.1:49204
at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Int32 timeout, Exception& exception)] No connection could be made because the target machine actively refused it 127.0.0.1:49204
at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Int32 timeout, Exception& exception)
[System.Net.WebException: Unable to connect to the remote server ---> System.Net.Sockets.SocketException: No connection could be made because the target machine actively refused it 127.0.0.1:49204
at System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
at System.Net.ServicePoint.ConnectSocketInternal(Boolean connectFailure, Socket s4, Socket s6, Socket& socket, IPAddress& address, ConnectSocketState state, IAsyncResult asyncResult, Int32 timeout, Exception& exception)
--- End of inner exception stack trace ---
at System.Net.HttpWebRequest.GetRequestStream(TransportContext& context)
at System.Net.HttpWebRequest.GetRequestStream()
at System.Web.Services.Protocols.SoapHttpClientProtocol.Invoke(String methodName, Object[] parameters)
at VaultClientNetLib.ClientService.VaultService.ValidateServiceVersions(Int32[] clientSupportedVersions)
at VaultClientNetLib.VaultConnection.Login(String strURLBase, String strUserLogin, String strPassword)] Unable to connect to the remote server
at System.Net.HttpWebRequest.GetRequestStream(TransportContext& context)
at System.Net.HttpWebRequest.GetRequestStream()
at System.Web.Services.Protocols.SoapHttpClientProtocol.Invoke(String methodName, Object[] parameters)
at VaultClientNetLib.ClientService.VaultService.ValidateServiceVersions(Int32[] clientSupportedVersions)
at VaultClientNetLib.VaultConnection.Login(String strURLBase, String strUserLogin, String strPassword)

Stack Trace:
at VaultClientNetLib.VaultConnection.Login(String strURLBase, String strUserLogin, String strPassword)
at VaultClientOperationsLib.ClientInstance.Login(String urlbase, String username, String password)
at VaultClientPresentationLib.GUIClientInstance.ConnectToServer(String& outserverPath, Boolean forceDialogShow, String& outprofileName, String& outusername, Boolean& outbUseSSL, Boolean& outbAutoLogin)
at VaultClientPresentationLib.GUIClientThread.ProcessCommand(GUIClientThreadCommand command, GUIClientThreadCommandResult& outputResult)
at VaultClientPresentationLib.GUIClientThread.Start()
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Threading.ThreadHelper.ThreadStart()

3/26/2014 2:11:47 PM <eventengine>: [GUIClientWorkerThread:7128] Event fired: VaultClientOperationsLib.ConnectionStateChangedEvent
3/26/2014 2:11:47 PM <connection>: [GUIClientWorkerThread:7128] Logout started.
3/26/2014 2:11:47 PM <statussearch>: [Main:6960] Connection state changed from Connecting to Disconnecting
3/26/2014 2:11:47 PM <emailview>: [Main:6960] Connection state changed from Connecting to Disconnecting
3/26/2014 2:11:48 PM <connection>: [GUIClientWorkerThread:7128] Logout finished.
3/26/2014 2:11:48 PM <generic>: [GUIClientWorkerThread:7128] SetActiveRepositoryID(id:-1)
3/26/2014 2:11:48 PM <eventengine>: [GUIClientWorkerThread:7128] Event fired: VaultClientOperationsLib.ChangeSetItemsChangedEvent
3/26/2014 2:11:48 PM <eventengine>: [GUIClientWorkerThread:7128] Event fired: VaultClientOperationsLib.ActiveRepositoryChangedEvent
3/26/2014 2:11:48 PM <eventengine>: [GUIClientWorkerThread:7128] Event fired: VaultClientOperationsLib.TreeStructureChangedEvent
3/26/2014 2:11:48 PM <repositoryexplorer>: [Main:6960] refresh requested while we were disabled
3/26/2014 2:11:48 PM <eventengine>: [GUIClientWorkerThread:7128] Event fired: VaultClientOperationsLib.ConnectionStateChangedEvent
3/26/2014 2:11:48 PM <repositoryexplorer>: [Main:6960] refresh requested while we were disabled
3/26/2014 2:11:48 PM <busy>: [GUIClientWorkerThread:7128] Setting GUI to unbusy from ConnectToServer.
3/26/2014 2:11:48 PM <repositoryexplorer>: [Main:6960] refresh requested while we were disabled
3/26/2014 2:11:48 PM <generic>: [GUIClientWorkerThread:7128] [System.Exception: Unable to connect to http://vault.domain.com/VaultService. No server was found at the specified URL. Please verify your network settings using the Options dialog under the Tools menu in the Vault GUI Client. Web Exception: Unable to connect to the remote server
at VaultClientNetLib.VaultConnection.Login(String strURLBase, String strUserLogin, String strPassword)
at VaultClientOperationsLib.ClientInstance.Login(String urlbase, String username, String password)
at VaultClientPresentationLib.GUIClientInstance.ConnectToServer(String& outserverPath, Boolean forceDialogShow, String& outprofileName, String& outusername, Boolean& outbUseSSL, Boolean& outbAutoLogin)
at VaultClientPresentationLib.GUIClientThread.ProcessCommand(GUIClientThreadCommand command, GUIClientThreadCommandResult& outputResult)] Unable to connect to http://vault.domain.com/VaultService. No server was found at the specified URL. Please verify your network settings using the Options dialog under the Tools menu in the Vault GUI Client. Web Exception: Unable to connect to the remote server
at VaultClientNetLib.VaultConnection.Login(String strURLBase, String strUserLogin, String strPassword)
at VaultClientOperationsLib.ClientInstance.Login(String urlbase, String username, String password)
at VaultClientPresentationLib.GUIClientInstance.ConnectToServer(String& outserverPath, Boolean forceDialogShow, String& outprofileName, String& outusername, Boolean& outbUseSSL, Boolean& outbAutoLogin)
at VaultClientPresentationLib.GUIClientThread.ProcessCommand(GUIClientThreadCommand command, GUIClientThreadCommandResult& outputResult)

Stack Trace:
at VaultClientPresentationLib.GUIClientInstance.ShowCommandException(Exception e, IWin32Window dialogOwner)
at VaultClientPresentationLib.GUIClientThread.ProcessCommand(GUIClientThreadCommand command, GUIClientThreadCommandResult& outputResult)
at VaultClientPresentationLib.GUIClientThread.Start()
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Threading.ThreadHelper.ThreadStart()

3/26/2014 2:11:48 PM <repositoryexplorer>: [Main:6960] refresh requested updateKnown is False
3/26/2014 2:11:48 PM <statussearch>: [Main:6960] Active repository changed to
3/26/2014 2:11:48 PM <statussearch>: [Main:6960] Connection state changed from Disconnecting to Unconnected
3/26/2014 2:11:49 PM <emailview>: [Main:6960] Active repository changed to
3/26/2014 2:11:49 PM <emailview>: [Main:6960] Connection state changed from Disconnecting to Unconnected
3/26/2014 2:11:53 PM <busy>: [GUIClientWorkerThread:7128] Setting GUI to busy from ConnectToServer
3/26/2014 2:11:57 PM <busy>: [GUIClientWorkerThread:7128] Setting GUI to unbusy from ConnectToServer.
3/26/2014 2:11:57 PM <statussearch>: [GUIClientWorkerThread:7128] StatusSearchScan run with DONTSEARCH. Reporting empty search results.

[lbauer]

3/26/2014 2:11:45 PM <emailview>: [Main:6960] Connection state changed from Unconnected to Connecting
3/26/2014 2:11:47 PM <generic>: [GUIClientWorkerThread:7128] [System.Net.Sockets.SocketException: No connection could be made because the target machine actively refused it 127.0.0.1:49204

I like to see the the Vault Server log for the time period of the client log.

The Vault server log is called sgvault.log and is in %windir%\temp\sgvault on the server machine. Email it to me at support at sourcegear.com, ATTN: Linda.

Please include a link to this forum post.

[craigr]

There's nothing in the Vault server log at this time that is associated with the problem user. I just see normal entries from the other two users that were on at the time. There's nothing that isn't clearly identified with other users and nothing at all around the specific time that we were trying to log her in.

There might be entries in the IIS log corresponding to these attempts but there doesn't seem to be any meaningful information there. Certainly not an error message or anything diagnostic. Just a request and a status 200 response.

That 127.0.0.1 IP looked odd -- is it normal to see a localhost IP address in this context?

Craig

[lbauer]

Are you using SSL or a port other than port 80 for the Vault Server?

Can the user connect with using the Vault Server machine's IP address?

If the user temporarily turns off the firewall on the client machine, can the client connect?

In Windows 7 go to "Internet Options" in "Connection" tab click on "LAN Settings" and uncheck everything.

Could a virus or anti-virus software be blocking the connection?

[craigr]

Somehow the proxy server got turned on. We've never ever checked that for any reason in 20 years. Must've been a Windows update. Not sure why they would do that.

Thanks for your help.

[lbauer]

Glad Vault is working on that machine now!

Let me know if we can be of assistance in the future.