search

microsoft / RTVS

R Tools for Visual Studio.
MIT License
390 stars 111 forks source link

Authentication error connecting to remote workspace #3334

Closed ghost closed 7 years ago

ghost commented 7 years ago

If we trying to connect with a user, who has not setup the remote workspace, user gets the following error: In R Interactive the message is: Reason: HTTP error while creating session on the machine 'xxxx'. Exception: The remote server returned an error: (401) Unauthorized. Connecting to workspace works for user who setup the workspace. Broker log says:

[2017-03-23 15:56:11Z] (I): Certificate issued by CN=server01

[2017-03-23 15:56:11Z] (I): Certificate issued to CN=server01

[2017-03-23 15:56:11Z] (T): Auto-detecting R ...

[2017-03-23 15:56:11Z] (T): R 3.3.2 detected at \"C:\Program Files\Microsoft\MRO-3.3.2\"

[2017-03-23 15:56:11Z] (I): 3 interpreters configured: [0] : Microsoft R Open (3.3.2) at "C:\Program Files\Microsoft\MRO-3.3.2\" [0] : MRO at "C:\Program Files\Microsoft\MRO-3.3.2" [1] : MSSQL R Services at "C:\Program Files\Microsoft SQL Server\MSSQL13.MSSQL01\R_SERVICES"

[2017-03-23 15:56:11Z] (D): Hosting starting

[2017-03-23 15:56:11Z] (D): Hosting started

[2017-03-23 15:56:23Z] (D): Connection id "0HL3HVJ316PV9" started.

[2017-03-23 15:56:23Z] (I): Request starting HTTP/1.1 PUT https://server01:5444/sessions/TestBrokerConnectionAsync_50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q_ application/json; charset=utf-8 47

[2017-03-23 15:56:23Z] (D): Request did not match any routes.

[2017-03-23 15:56:23Z] (I): Basic was not authenticated. Failure message: No authorization header.

[2017-03-23 15:56:23Z] (I): AuthenticationScheme: Basic was challenged.

[2017-03-23 15:56:23Z] (I): Request finished in 110.5711ms 401

[2017-03-23 15:56:23Z] (D): Connection id "0HL3HVJ316PV9" completed keep alive response.

[2017-03-23 15:56:23Z] (I): Request starting HTTP/1.1 PUT https://server01:5444/sessions/TestBrokerConnectionAsync_50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q_ application/json; charset=utf-8 47

[2017-03-23 15:56:23Z] (D): Request did not match any routes.

[2017-03-23 15:56:23Z] (T): Attempting log on for user: testdomain\user1

[2017-03-23 15:56:23Z] (E): Log on failed for user: testdomain\user1

[2017-03-23 15:56:23Z] (I): Basic was not authenticated. Failure message: Invalid basic authentication credentials.

[2017-03-23 15:56:23Z] (I): AuthenticationScheme: Basic was challenged.

[2017-03-23 15:56:23Z] (I): Request finished in 40.5699ms 401

[2017-03-23 15:56:23Z] (D): Connection id "0HL3HVJ316PV9" completed keep alive response.

[2017-03-23 15:56:26Z] (I): Request starting HTTP/1.1 PUT https://server01:5444/sessions/TestBrokerConnectionAsync_50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q_ application/json; charset=utf-8 47

[2017-03-23 15:56:26Z] (D): Request did not match any routes.

[2017-03-23 15:56:26Z] (I): Basic was not authenticated. Failure message: No authorization header.

[2017-03-23 15:56:26Z] (I): AuthenticationScheme: Basic was challenged.

[2017-03-23 15:56:26Z] (I): Request finished in 0.4209ms 401

[2017-03-23 15:56:26Z] (D): Connection id "0HL3HVJ316PV9" completed keep alive response.

[2017-03-23 15:56:26Z] (I): Request starting HTTP/1.1 PUT https://server01:5444/sessions/TestBrokerConnectionAsync_50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q_ application/json; charset=utf-8 47

[2017-03-23 15:56:26Z] (D): Request did not match any routes.

[2017-03-23 15:56:26Z] (T): Attempting log on for user: testdomain\user1

[2017-03-23 15:56:26Z] (T): Log on succeeded for user: testdomain\user1

[2017-03-23 15:56:26Z] (T): User testdomain\user1 profile directory: C:\Users\user1

[2017-03-23 15:56:26Z] (I): HttpContext.User merged via AutomaticAuthentication from authenticationScheme: Basic.

[2017-03-23 15:56:27Z] (D): Request successfully matched the route with name '' and template 'sessions/{id}'.

[2017-03-23 15:56:27Z] (D): Action 'Microsoft.R.Host.Broker.Sessions.SessionsController.Delete (Microsoft.R.Host.Broker)' with id '544689af-4e6a-4f9e-aa26-e2113ab2c5df' did not match the constraint 'Microsoft.AspNetCore.Mvc.Internal.HttpMethodActionConstraint'

[2017-03-23 15:56:27Z] (D): Executing action Microsoft.R.Host.Broker.Sessions.SessionsController.PutAsync (Microsoft.R.Host.Broker)

[2017-03-23 15:56:27Z] (I): Authorization was successful for user: testdomain\user1.

[2017-03-23 15:56:27Z] (I): Executing action method Microsoft.R.Host.Broker.Sessions.SessionsController.PutAsync (Microsoft.R.Host.Broker) with arguments (TestBrokerConnectionAsync50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q, Microsoft.R.Host.Protocol.SessionCreateRequest) - ModelState is Valid

[2017-03-23 15:56:27Z] (T): Creating user environment variables for user testdomain\user1 with profile directory C:\Users\user1

[2017-03-23 15:56:27Z] (T): USERNAME = user1

[2017-03-23 15:56:27Z] (T): HOMEDRIVE = C:

[2017-03-23 15:56:27Z] (T): HOMEPATH = \Users\user1

[2017-03-23 15:56:27Z] (T): USERPROFILE = C:\Users\user1

[2017-03-23 15:56:27Z] (T): APPDATA = C:\Users\user1\AppData\Roaming

[2017-03-23 15:56:27Z] (T): LOCALAPPDATA = C:\Users\user1\AppData\Local

[2017-03-23 15:56:27Z] (T): TEMP = C:\Users\user1\AppData\Local\Temp

[2017-03-23 15:56:27Z] (T): TMP = C:\Users\user1\AppData\Local\Temp

[2017-03-23 15:56:27Z] (T): R_HOME = C:\PROGRA~1\MICROS~4\MSSQL1~1.MSS\R_SERV~2

[2017-03-23 15:56:27Z] (T): PATH = C:\Program Files\Microsoft SQL Server\MSSQL13.MSSQL01\R_SERVICES\bin\x64;C:\Program Files\Teradata\Client\15.00\ODBC Driver for Teradata nt-x8664\Lib;C:\Program Files (x86)\Teradata\Client\15.00\ODBC Driver for Teradata\Lib;C:\Program Files\Teradata\Client\15.00\bin\;C:\Program Files (x86)\Teradata\Client\15.00\bin\;C:\Program Files\Microsoft MPI\Bin\;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\Microsoft SQL Server\130\Tools\Binn\;C:\Program Files\Microsoft SQL Server\130\Tools\Binn\;C:\Program Files (x86)\Microsoft SQL Server\130\DTS\Binn\;C:\Program Files\Microsoft SQL Server\130\DTS\Binn\;C:\Program Files\Microsoft SQL Server\Client SDK\ODBC\130\Tools\Binn\;C:\Program Files (x86)\Microsoft SQL Server\Client SDK\ODBC\130\Tools\Binn\;C:\Program Files (x86)\Microsoft SQL Server\130\Tools\Binn\ManagementStudio\

[2017-03-23 15:56:27Z] (I): Starting R session for connection TestBrokerConnectionAsync50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q of user testdomain\user1 with command line: "C:\Program Files\R Remote Service for Visual Studio\1.0\Microsoft.R.Host.exe" --rhost-suppress-ui --rhost-name "TestBrokerConnectionAsync50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q" --rhost-log-verbosity 1

[2017-03-23 15:56:27Z] (I): R session started for connection TestBrokerConnectionAsync50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q of user testdomain\user1

[2017-03-23 15:56:27Z] (D): Executed action method Microsoft.R.Host.Broker.Sessions.SessionsController.PutAsync (Microsoft.R.Host.Broker), returned result Microsoft.AspNetCore.Mvc.ObjectResult.

[2017-03-23 15:56:27Z] (D): Selected output formatter 'Microsoft.AspNetCore.Mvc.Formatters.JsonOutputFormatter' and content type 'application/json' to write the response.

[2017-03-23 15:56:27Z] (I): Executing ObjectResult, writing value Microsoft.AspNetCore.Mvc.ControllerContext.

[2017-03-23 15:56:28Z] (I): Executed action Microsoft.R.Host.Broker.Sessions.SessionsController.PutAsync (Microsoft.R.Host.Broker) in 899.5403ms

[2017-03-23 15:56:28Z] (I): Request finished in 1204.6637ms 200 application/json; charset=utf-8

[2017-03-23 15:56:28Z] (D): Connection id "0HL3HVJ316PV9" completed keep alive response.

[2017-03-23 15:56:28Z] (D): Connection id "0HL3HVJ316PVA" started.

[2017-03-23 15:56:28Z] (I): Request starting HTTP/1.1 GET https://server01:5444/sessions/TestBrokerConnectionAsync_50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q_/pipe

[2017-03-23 15:56:28Z] (D): Request did not match any routes.

[2017-03-23 15:56:28Z] (I): Basic was not authenticated. Failure message: No authorization header.

[2017-03-23 15:56:28Z] (I): AuthenticationScheme: Basic was challenged.

[2017-03-23 15:56:28Z] (I): Request finished in 0.2417ms 401

[2017-03-23 15:56:28Z] (D): Connection id "0HL3HVJ316PVA" disconnecting.

[2017-03-23 15:56:28Z] (D): Connection id "0HL3HVJ316PVA" received FIN.

[2017-03-23 15:56:28Z] (D): Connection id "0HL3HVJ316PVA" sending FIN.

[2017-03-23 15:56:28Z] (D): Connection id "0HL3HVJ316PVA" sent FIN with status "0".

[2017-03-23 15:56:28Z] (D): Connection id "0HL3HVJ316PVA" stopped.

[2017-03-23 15:56:28Z] (D): Connection id "0HL3HVJ316PVB" started.

[2017-03-23 15:56:29Z] (I): Request starting HTTP/1.1 GET https://server01:5444/sessions/TestBrokerConnectionAsync_50MLBdmh4OstPi5wiq6ssTtQFVWLnNRYOniCQqulr0Q_/pipe

[2017-03-23 15:56:29Z] (D): Request did not match any routes.

[2017-03-23 15:56:29Z] (T): Attempting log on for user: testdomain\user1

[2017-03-23 15:56:29Z] (E): Log on failed for user: testdomain\user1

[2017-03-23 15:56:29Z] (I): Basic was not authenticated. Failure message: Invalid basic authentication credentials.

[2017-03-23 15:56:29Z] (I): AuthenticationScheme: Basic was challenged.

[2017-03-23 15:56:29Z] (I): Request finished in 22.4735ms 401

[2017-03-23 15:56:29Z] (D): Connection id "0HL3HVJ316PVB" disconnecting.

[2017-03-23 15:56:29Z] (D): Connection id "0HL3HVJ316PVB" sending FIN.

[2017-03-23 15:56:29Z] (D): Connection id "0HL3HVJ316PVB" sent FIN with status "0".

[2017-03-23 15:56:29Z] (D): Connection id "0HL3HVJ316PVB" stopped.

MikhailArkhipov commented 7 years ago

What build is it (VS Help | About)? This reminds me of a race condition we fixed some time ago.

ghost commented 7 years ago

VS Build's 14.0.25420.01 Update 3 (Enterprise 2015)

ghost commented 7 years ago

Strange thing, connection works for the user who setup the remote workspace, but not for anybody else.

MikhailArkhipov commented 7 years ago

I mean RTVS version

ghost commented 7 years ago

It's 0.6.30118.1122

ghost commented 7 years ago

It seems the success is depending from the user's password...

MikhailArkhipov commented 7 years ago

Please upgrade to 1.0 at https://aka.ms/rtvs-current

MikhailArkhipov commented 7 years ago

No it was a race condition bug back in 0.6

MikhailArkhipov commented 7 years ago

https://aka.ms/rtvs-remote

MikhailArkhipov commented 7 years ago

Please reopen if you still have problem with 1.0.