Error authenticating to Teams (403) Forbidden

markroloff commented 5 years ago

Worked through the docs for setting up the Teams backend and have hit a roadblack. Bot appears to be receiving messages fine but fails to authenticate to Teams when attempting to convert the user id. Repeated in both private and public teams.

Expected Behavior

@poshbot !about

bot proceeds to tell me nice things about itself

Current Behavior

Shell output displays...

WARNING: {"DataTime":"2019-01-26 06:37:32Z","Class":"TeamsBackend","Method":"UserIdToUsername","Severity":"Warning","LogLevel":"Debug","Message":"User [28:a2325a1a-9f5a-484a-b8d3-4f72324de4b1] not found. Refreshing users","Data":{}}
VERBOSE: GET https://smba.trafficmanager.net/amer/v3/conversations/19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype/members/ with 0-byte payload

PoshBot.log shows...

{"DataTime":"2019-01-26 06:37:32Z","Class":"TeamsBackend","Method":"ReceiveMessage","Severity":"Normal","LogLevel":"Debug","Message":"Received message","Data":"{\r\n  \"text\": \"\u003cat\u003ePoshBot\u003c/at\u003e !about\\n\",\r\n  \"textFormat\": \"plain\",\r\n  \"attachments\": [\r\n    {\r\n      \"contentType\": \"text/html\",\r\n      \"content\": \"\u003cdiv\u003e\u003cdiv\u003e\u003cspan itemscope=\\\"\\\" itemtype=\\\"http://schema.skype.com/Mention\\\" itemid=\\\"0\\\"\u003ePoshBot\u003c/span\u003e !about\u003c/div\u003e\\n\u003c/div\u003e\"\r\n    }\r\n  ],\r\n  \"type\": \"message\",\r\n  \"timestamp\": \"2019-01-26T06:37:32.014Z\",\r\n  \"localTimestamp\": \"2019-01-26T06:37:32.014+00:00\",\r\n  \"id\": \"1548484651977\",\r\n  \"channelId\": \"msteams\",\r\n  \"serviceUrl\": \"https://smba.trafficmanager.net/amer/\",\r\n  \"from\": {\r\n    \"id\": \"29:1WBie1APNt02bKQAbHdQTXb6QGWhBZYL-4nb8V6fZWeyQmedyJuyxXwczpRGzHSCsQDTwLshY29AGW4lYeMRPYA\",\r\n    \"name\": \"Mark Roloff\",\r\n    \"aadObjectId\": \"1249a3a7-f017-49c8-8b86-edc258cbddf2\"\r\n  },\r\n  \"conversation\": {\r\n    \"isGroup\": true,\r\n    \"conversationType\": \"channel\",\r\n    \"id\": \"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype;messageid=1548484651977\"\r\n  },\r\n  \"recipient\": {\r\n    \"id\": \"28:a2325a1a-9f5a-484a-b8d3-4f72324de4b1\",\r\n    \"name\": \"PoshBot\"\r\n  },\r\n  \"entities\": [\r\n    {\r\n      \"mentioned\": {\r\n        \"id\": \"28:a2325a1a-9f5a-484a-b8d3-4f72324de4b1\",\r\n        \"name\": \"PoshBot\"\r\n      },\r\n      \"text\": \"\u003cat\u003ePoshBot\u003c/at\u003e\",\r\n      \"type\": \"mention\"\r\n    },\r\n    {\r\n      \"locale\": \"en-US\",\r\n      \"country\": \"US\",\r\n      \"platform\": \"Windows\",\r\n      \"type\": \"clientInfo\"\r\n    }\r\n  ],\r\n  \"channelData\": {\r\n    \"teamsChannelId\": \"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype\",\r\n    \"teamsTeamId\": \"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype\",\r\n    \"channel\": {\r\n      \"id\": \"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype\"\r\n    },\r\n    \"team\": {\r\n      \"id\": \"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype\"\r\n    },\r\n    \"tenant\": {\r\n      \"id\": \"\"\r\n    }\r\n  }\r\n}"}
{"DataTime":"2019-01-26 06:37:32Z","Class":"TeamsBackend","Method":"ReceiveMessage","Severity":"Normal","LogLevel":"Debug","Message":"Message type is [Message]","Data":{}}
{"DataTime":"2019-01-26 06:37:32Z","Class":"TeamsBackend","Method":"ReceiveMessage","Severity":"Normal","LogLevel":"Debug","Message":"Raw message","Data":{"text":"\u003cat\u003ePoshBot\u003c/at\u003e !about\n","textFormat":"plain","attachments":[{"contentType":"text/html","content":"\u003cdiv\u003e\u003cdiv\u003e\u003cspan itemscope=\"\" itemtype=\"http://schema.skype.com/Mention\" itemid=\"0\"\u003ePoshBot\u003c/span\u003e !about\u003c/div\u003e\n\u003c/div\u003e"}],"type":"message","timestamp":"2019-01-26T06:37:32.014Z","localTimestamp":"2019-01-26T06:37:32.014+00:00","id":"1548484651977","channelId":"msteams","serviceUrl":"https://smba.trafficmanager.net/amer/","from":{"id":"29:1WBie1APNt02bKQAbHdQTXb6QGWhBZYL-4nb8V6fZWeyQmedyJuyxXwczpRGzHSCsQDTwLshY29AGW4lYeMRPYA","name":"Mark Roloff","aadObjectId":"1249a3a7-f017-49c8-8b86-edc258cbddf2"},"conversation":{"isGroup":true,"conversationType":"channel","id":"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype;messageid=1548484651977"},"recipient":{"id":"28:a2325a1a-9f5a-484a-b8d3-4f72324de4b1","name":"PoshBot"},"entities":[{"mentioned":{"id":"28:a2325a1a-9f5a-484a-b8d3-4f72324de4b1","name":"PoshBot"},"text":"\u003cat\u003ePoshBot\u003c/at\u003e","type":"mention"},{"locale":"en-US","country":"US","platform":"Windows","type":"clientInfo"}],"channelData":{"teamsChannelId":"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype","teamsTeamId":"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype","channel":{"id":"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype"},"team":{"id":"19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype"},"tenant":{"id":""}}}}
{"DataTime":"2019-01-26 06:37:32Z","Class":"TeamsBackend","Method":"UserIdToUsername","Severity":"Warning","LogLevel":"Debug","Message":"User [28:a2325a1a-9f5a-484a-b8d3-4f72324de4b1] not found. Refreshing users","Data":{}}
{"DataTime":"2019-01-26 06:37:32Z","Class":"TeamsBackend","Method":"LoadUsers","Severity":"Normal","LogLevel":"Debug","Message":"Getting Teams users","Data":{}}
{"DataTime":"2019-01-26 06:37:32Z","Class":"TeamsBackend","Method":"ReceiveMessage","Severity":"Error","LogLevel":"Info","Message":"Error authenticating to Teams","Data":{"CommandName":"Invoke-RestMethod","Message":"The remote server returned an error: (403) Forbidden.","TargetObject":{"AllowAutoRedirect":true,"AllowWriteStreamBuffering":true,"AllowReadStreamBuffering":false,"HaveResponse":true,"KeepAlive":true,"Pipelined":true,"PreAuthenticate":false,"UnsafeAuthenticatedConnectionSharing":false,"SendChunked":false,"AutomaticDecompression":0,"MaximumResponseHeadersLength":64,"ClientCertificates":[],"CookieContainer":{"Capacity":300,"Count":0,"MaxCookieSize":4096,"PerDomainCapacity":20},"SupportsCookieContainer":true,"RequestUri":"https://smba.trafficmanager.net/amer/v3/conversations/19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype/members/","ContentLength":0,"Timeout":-1,"ReadWriteTimeout":300000,"ContinueTimeout":350,"Address":"https://smba.trafficmanager.net/amer/v3/conversations/19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype/members/","ContinueDelegate":null,"ServicePoint":{"BindIPEndPointDelegate":null,"ConnectionLeaseTimeout":-1,"Address":"https://smba.trafficmanager.net/amer/v3/conversations/19:ca55cabfff944c88a0525ed6d84b96c5@thread.skype/members/","MaxIdleTime":100000,"UseNagleAlgorithm":true,"ReceiveBufferSize":-1,"Expect100Continue":false,"IdleSince":"\/Date(1548484652693)\/","ProtocolVersion":{"Major":1,"Minor":1,"Build":-1,"Revision":-1,"MajorRevision":-1,"MinorRevision":-1},"ConnectionName":"https","ConnectionLimit":2,"CurrentConnections":0,"Certificate":{"Handle":2159064688192,"Issuer":"CN=Microsoft IT TLS CA 5, OU=Microsoft IT, O=Microsoft Corporation, L=Redmond, S=Washington, C=US","Subject":"CN=*.botapi.skype.com"},"ClientCertificate":null,"SupportsPipelining":true},"Host":"smba.trafficmanager.net","MaximumAutomaticRedirections":50,"Method":"GET","Credentials":null,"UseDefaultCredentials":false,"ConnectionGroupName":null,"Headers":["Authorization","User-Agent","Host"],"Proxy":{"Credentials":null},"ProtocolVersion":{"Major":1,"Minor":1,"Build":-1,"Revision":-1,"MajorRevision":-1,"MinorRevision":-1},"ContentType":null,"MediaType":null,"TransferEncoding":null,"Connection":null,"Accept":null,"Referer":null,"UserAgent":"Mozilla/5.0 (Windows NT; Windows NT 10.0; en-US) WindowsPowerShell/5.1.14393.2636","Expect":null,"IfModifiedSince":"\/Date(-62135571600000)\/","Date":"\/Date(-62135571600000)\/","ServerCertificateValidationCallback":null,"CreatorInstance":{},"CachePolicy":{"Level":1},"AuthenticationLevel":1,"ImpersonationLevel":4},"Position":"At C:\\Program Files\\WindowsPowerShell\\Modules\\PoshBot\\0.11.4\\PoshBot.psm1:7940 char:24\r\n+             $members = Invoke-RestMethod -Uri $uri -Headers $headers\r\n+                        ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~","CategoryInfo":"InvalidOperation: (System.Net.HttpWebRequest:HttpWebRequest) [Invoke-RestMethod], WebException","FullyQualifiedErrorId":"WebCmdletWebResponseException,Microsoft.PowerShell.Commands.InvokeRestMethodCommand"}}

Your Environment

Module version used: 0.11.4
Operating System and PowerShell version: Windows Server 2016 Datacenter and PSVersion 5.1.14393.2636

devblackops commented 5 years ago

@markroloff Do you have your bot framework id/password defined in the backend configuration? PoshBot will use an SAS key to receive messages from Service Bus and the bot id/pwd to post messages back to Teams or to retrieve user information like it is trying to do in this case.

markroloff commented 5 years ago

@devblackops I double-checked those last night and ran into the same issue. For the sake of my sanity, I'm going to take a scorched-earth approach and start it over from scratch just to make sure I didn't miss something silly. Will report back.

devblackops commented 5 years ago

Interesting. Are you going to run through the docs end-to-end? I'd love to know if I missed a key step or if something is unclear.

You may also try and set this in your script:

[Net.ServicePointManager]::SecurityProtocol = [Net.SecurityProtocolType]::Tls12

This was fixed in https://github.com/poshbotio/PoshBot/issues/138

markroloff commented 5 years ago

Sorry for the delay. Been swamped with work. Got it working this time around, so I must have fubared something along the way originally. I suspect it was with configuring the bot manifest in Teams.

However, after going through the steps more closely, I found that the function app's connection string name differs from what gets configured in the settings. I'll send a PR to you for that.

delrio1110 commented 5 years ago

@markroloff how did you fix this issue? Im having the same problem.

poshbotio / PoshBot