Jump to content

HttpAsyncTaskHandler error


Angelblue05

Recommended Posts

Angelblue05

I'm posting on behalf of @@saitoh183. He's experiencing some issues with the XBMB3C beta version. Unfortunately, there's nothing showing up in the xbmc logs. I only have MBS server logs to go off from. I'm trying to figure out what exactly is the error related to. If someone could help me understand what it means or if anything else sticks out.  :) I compared my log to his. 

 

Version: MBS 3.0.5416.0, XBMB3C 0.9.60306 (same versions for both of us)

 

MBS server log error [saitoh183]: I understand it's an authentication error. The error repeats itself 5-6 times every minute or so. What could cause the header not to authenticate?

2014-11-03 03:11:08.7810 Debug - HttpServer: HTTP Response 401 to 192.168.13.102. Response time: 0 ms.
	Url: http://192.168.13.198:8096/mediabrowser/Users/2f68b127e5384f20d04da8c4c05366db/Items?Limit=20&Fields=ParentId,Overview&CollapseBoxSetItems=false&Recursive=true&IncludeItemTypes=Movie&Filters=IsFavorite&format=json
2014-11-03 03:11:11.7811 Debug - HttpServer: HTTP GET http://192.168.13.198:8096/mediabrowser/Users/2f68b127e5384f20d04da8c4c05366db/Items?Limit=20&Fields=ParentId,Overview&CollapseBoxSetItems=false&Recursive=true&IncludeItemTypes=Movie&Filters=IsFavorite&format=json
	Ip: 192.168.13.102:59627. Headers: X-MediaBrowser-Token=,Accept-Charset=UTF-8,*,Accept-Encoding=gzip,Host=192.168.13.198:8096
2014-11-03 03:11:11.7811 Error - HttpAsyncTaskHandler: Error occured while Processing Request: Exception of type 'MediaBrowser.Server.Implementations.Security.AuthenticationException' was thrown.
	Exception of type 'MediaBrowser.Server.Implementations.Security.AuthenticationException' was thrown.
	MediaBrowser.Server.Implementations.Security.AuthenticationException
	   at MediaBrowser.Server.Implementations.Session.SessionManager.ValidateSecurityToken(String token)
	   at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.ValidateUser(IRequest req, IResponse response, IAuthenticated authAttribtues)
	   at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.Authenticate(IRequest request, IResponse response, Object requestDto, IAuthenticated authAttribtues)
	   at MediaBrowser.Controller.Net.AuthenticatedAttribute.RequestFilter(IRequest request, IResponse response, Object requestDto)
	   at ServiceStack.ServiceStackHost.ApplyRequestFilters(IRequest req, IResponse res, Object requestDto)
	   at ServiceStack.Host.RestHandler.ProcessRequestAsync(IRequest httpReq, IResponse httpRes, String operationName)

Compared to my server log [angelblue05]: Mine seems to exit gracefully. I've done a quick search and "Exiting HttpConnection" does not appears in my brother's log (instead the error above appears). What does Exiting HttpConnection.OnReadInternal pertains to? 

2014-11-02 23:59:49.3473 Debug - HttpServer: HTTP GET http://192.168.0.190:8096/mediabrowser/Users/6a9cb6714653c32997a4ef3d56a13743/Items/ae4e610ec2546d73ea2f2b2308eda2d5?format=json
	Ip: 192.168.0.190:56385. Headers: Host=192.168.0.190:8096,Accept-Charset=UTF-8,*,Accept-encoding=gzip,Authorization=MediaBrowser UserId="6a9cb6714653c32997a4ef3d56a13743",Client="XBMC",Device="XBMC",DeviceId="D736AAF672FA494EA4A020CC9E2948BE",Version="0.9.60306",X-MediaBrowser-Token=b01e76e4e1ef4e9db751756dd5bc1650
2014-11-02 23:59:49.3643 Debug - HttpServer: HTTP Response 200 to 192.168.0.190. Response time: 3.0001 ms.
	Url: http://192.168.0.190:8096/mediabrowser/Users/6a9cb6714653c32997a4ef3d56a13743/Items/ae4e610ec2546d73ea2f2b2308eda2d5?format=json
2014-11-02 23:59:49.3643 Debug - HttpServer: Exiting HttpConnection.OnReadInternal because nread=0. ConnectionId: a40717fafa9240cdbb748925dcf17db6

Is this related? Could the websocket error explain the error above?

2014-11-03 06:05:33.5810 Error - HttpServer: Error receiving web socket message
	An internal WebSocket error occurred. Please see the innerException, if present, for more details. 
	System.Net.WebSockets.WebSocketException
	   at System.Net.WebSockets.WebSocketBase.ThrowIfConvertibleException(String methodName, Exception exception, CancellationToken cancellationToken, Boolean aborted)
	   at System.Net.WebSockets.WebSocketBase.<ReceiveAsyncCore>d__1.MoveNext()
	--- End of stack trace from previous location where exception was thrown ---
	   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
	   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
	   at MediaBrowser.Server.Implementations.HttpServer.NativeWebSocket.<ReceiveBytesAsync>d__4.MoveNext()
	--- End of stack trace from previous location where exception was thrown ---
	   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
	   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
	   at MediaBrowser.Server.Implementations.HttpServer.NativeWebSocket.<Receive>d__0.MoveNext()
	InnerException: System.Net.HttpListenerException
	An operation was attempted on a nonexistent network connection
	   at System.Net.WebSockets.WebSocketHttpListenerDuplexStream.ReadAsyncFast(HttpListenerAsyncEventArgs eventArgs)
	   at System.Net.WebSockets.WebSocketHttpListenerDuplexStream.<ReadAsyncCore>d__0.MoveNext()
	--- End of stack trace from previous location where exception was thrown ---
	   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
	   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
	   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
	   at System.Net.WebSockets.WebSocketBase.WebSocketOperation.<Process>d__47.MoveNext()
	--- End of stack trace from previous location where exception was thrown ---
	   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
	   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
	   at System.Net.WebSockets.WebSocketBase.<ReceiveAsyncCore>d__1.MoveNext()
Edited by Angelblue05
Link to comment
Share on other sites

saitoh183

I noticed that the error

2014-11-03 03:11:08.7810 Debug - HttpServer: HTTP Response 401 to 192.168.13.102. Response time: 0 ms.
	Url: http://192.168.13.198:8096/mediabrowser/Users/2f68b127e5384f20d04da8c4c05366db/Items?Limit=20&Fields=ParentId,Overview&CollapseBoxSetItems=false&Recursive=true&IncludeItemTypes=Movie&Filters=IsFavorite&format=json
2014-11-03 03:11:11.7811 Debug - HttpServer: HTTP GET http://192.168.13.198:8096/mediabrowser/Users/2f68b127e5384f20d04da8c4c05366db/Items?Limit=20&Fields=ParentId,Overview&CollapseBoxSetItems=false&Recursive=true&IncludeItemTypes=Movie&Filters=IsFavorite&format=json
	Ip: 192.168.13.102:59627. Headers: X-MediaBrowser-Token=,Accept-Charset=UTF-8,*,Accept-Encoding=gzip,Host=192.168.13.198:8096
2014-11-03 03:11:11.7811 Error - HttpAsyncTaskHandler: Error occured while Processing Request: Exception of type 'MediaBrowser.Server.Implementations.Security.AuthenticationException' was thrown.
	Exception of type 'MediaBrowser.Server.Implementations.Security.AuthenticationException' was thrown.
	MediaBrowser.Server.Implementations.Security.AuthenticationException
	   at MediaBrowser.Server.Implementations.Session.SessionManager.ValidateSecurityToken(String token)
	   at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.ValidateUser(IRequest req, IResponse response, IAuthenticated authAttribtues)
	   at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.Authenticate(IRequest request, IResponse response, Object requestDto, IAuthenticated authAttribtues)
	   at MediaBrowser.Controller.Net.AuthenticatedAttribute.RequestFilter(IRequest request, IResponse response, Object requestDto)
	   at ServiceStack.ServiceStackHost.ApplyRequestFilters(IRequest req, IResponse res, Object requestDto)
	   at ServiceStack.Host.RestHandler.ProcessRequestAsync(IRequest httpReq, IResponse httpRes, String operationName)

seems to be related to Movie Favorite. Because this line

Url: http://192.168.13.198:8096/mediabrowser/Users/2f68b127e5384f20d04da8c4c05366db/Items?Limit=20&Fields=ParentId,Overview&CollapseBoxSetItems=false&Recursive=true&IncludeItemTypes=Movie&Filters=IsFavorite&format=json 

is always the URL (Users/2f68b127e5384f20d04da8c4c05366db will be different when i use my other xbmc profile) that precedes the error. 

 

I have Movie favorite added as a menu item in both my XBMC profiles. Could it be that this view is broken in some way? I can still browse movies added in Favorite despite the error.

Edited by saitoh183
Link to comment
Share on other sites

Angelblue05

I think I figured out why it's not working but I don't know the steps to solving this. It seems there the MediaBrowser token is missing when received by MBS. 

 

Here is an example:

 

XBMB3C header:

20:21:40 T:4628  NOTICE: XBMB3C DownloadUtils -> DownloadUtils -> Returning saved UserID : ce7fb6896465c21df11271e13a57a7b6UserName: test
20:21:40 T:4628  NOTICE: XBMB3C DownloadUtils -> DownloadUtils -> Returning saved AccessToken : a37a2a7e2bc646179c2d717842dd918d
20:21:40 T:4628  NOTICE: XBMB3C DownloadUtils -> Authentication Header : {'Accept-Charset': 'UTF-8,*', 'Accept-encoding': 'gzip', 'Authorization': 'MediaBrowser UserId="ce7fb6896465c21df11271e13a57a7b6",Client="XBMC",Device="Upstairs",DeviceId="890FF46F869B407C9D72DE5C486DAC6C",Version="0.9.60306"', 'X-MediaBrowser-Token': 'a37a2a7e2bc646179c2d717842dd918d'}
20:21:40 T:4628  NOTICE: XBMB3C DownloadUtils -> HEADERS : {'Accept-Charset': 'UTF-8,*', 'Accept-encoding': 'gzip', 'Authorization': 'MediaBrowser UserId="ce7fb6896465c21df11271e13a57a7b6",Client="XBMC",Device="Upstairs",DeviceId="890FF46F869B407C9D72DE5C486DAC6C",Version="0.9.60306"', 'X-MediaBrowser-Token': 'a37a2a7e2bc646179c2d717842dd918d'}

MBS server log: The second header is missing the MediaBrowser Token. It is in the header from XBMB3C. What could cause this? 

2014-11-03 20:21:41.3860 Debug - HttpServer: HTTP GET http://192.168.13.198:8096/mediabrowser/Users/ce7fb6896465c21df11271e13a57a7b6/Items/1166345867c2bb242144e1ac7705fa7d?format=json
    Ip: 192.168.13.102:49658. Headers: X-MediaBrowser-Token=a37a2a7e2bc646179c2d717842dd918d,Accept-Charset=UTF-8,*,Accept-Encoding=gzip,Authorization=MediaBrowser UserId="ce7fb6896465c21df11271e13a57a7b6",Client="XBMC",Device="Upstairs",DeviceId="890FF46F869B407C9D72DE5C486DAC6C",Version="0.9.60306",Host=192.168.13.198:8096
2014-11-03 20:21:41.3860 Debug - HttpServer: HTTP GET http://192.168.13.198:8096/mediabrowser/Users/ce7fb6896465c21df11271e13a57a7b6/Items?Limit=20&Fields=ParentId,Overview&CollapseBoxSetItems=false&Recursive=true&IncludeItemTypes=Movie&Filters=IsFavorite&format=json
	Ip: 192.168.13.102:49659. Headers: X-MediaBrowser-Token=,Accept-Charset=UTF-8,*,Accept-Encoding=gzip,Host=192.168.13.198:8096
Edited by Angelblue05
Link to comment
Share on other sites

Angelblue05

This issue has been resolved by reinstalling the beta repo. Seems there was an old setting that lingered and conflicted with the new security api.

Link to comment
Share on other sites

  • 4 weeks later...
wesbronco75

I have been using MB for about 5 years now and this is the first error I have ever gotten. It seems to have just started within the last month or so (I have not used MB in a while and I have it auto update). I am running MB3 server Version 3.0.5445.5 and Media Browser Classic (in WMC) I have recently gotten this error. I have done a new install of the MB3 server and this did not fix the problem. Any body got any new ideas to fix the problem? I don't know how to attach my entire log file without filling up the whole screen but see below for a portion of it where it shows the error.

 

2014-11-29 17:02:10.4157 Debug - HttpServer: HTTP GET http://192.168.1.142:8096/mediabrowser/System/Info?format=Json

Ip: 192.168.1.142:50657. Headers: Authorization=MediaBrowser Client="MB-Classic", Version="3.0.196.0", DeviceId="00C0A8F75B8A", Device="WES-PC/Wes",Host=192.168.1.142:8096,Connection=Keep-Alive
2014-11-29 17:02:10.4157 Error - HttpAsyncTaskHandler: Error occured while Processing Request: Access token is invalid or expired.
Access token is invalid or expired.
MediaBrowser.Controller.Net.SecurityException
  at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.ValidateSecurityToken(IServiceRequest request, String token)
  at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.ValidateUser(IServiceRequest request, IAuthenticationAttributes authAttribtues)
  at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.Authenticate(IServiceRequest request, IAuthenticationAttributes authAttribtues)
  at MediaBrowser.Controller.Net.AuthenticatedAttribute.RequestFilter(IRequest request, IResponse response, Object requestDto)
  at ServiceStack.ServiceStackHost.ApplyRequestFiltersSingle(IRequest req, IResponse res, Object requestDto)
  at ServiceStack.ServiceStackHost.ApplyRequestFilters(IRequest req, IResponse res, Object requestDto)
  at ServiceStack.Host.RestHandler.ProcessRequestAsync(IRequest httpReq, IResponse httpRes, String operationName)
 
2014-11-29 17:02:10.4317 Debug - HttpServer: HTTP Response 401 to 192.168.1.142. Response time: 18.0011 ms.
2014-11-29 17:02:10.4317 Debug - HttpServer: HTTP GET http://192.168.1.142:8096/mediabrowser/System/Configuration?format=Json
Ip: 192.168.1.142:50657. Headers: Authorization=MediaBrowser Client="MB-Classic", Version="3.0.196.0", DeviceId="00C0A8F75B8A", Device="WES-PC/Wes",Host=192.168.1.142:8096
2014-11-29 17:02:10.4317 Error - HttpAsyncTaskHandler: Error occured while Processing Request: Access token is invalid or expired.
Access token is invalid or expired.
MediaBrowser.Controller.Net.SecurityException
  at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.ValidateSecurityToken(IServiceRequest request, String token)
  at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.ValidateUser(IServiceRequest request, IAuthenticationAttributes authAttribtues)
  at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.Authenticate(IServiceRequest request, IAuthenticationAttributes authAttribtues)
  at MediaBrowser.Controller.Net.AuthenticatedAttribute.RequestFilter(IRequest request, IResponse response, Object requestDto)
  at ServiceStack.ServiceStackHost.ApplyRequestFiltersSingle(IRequest req, IResponse res, Object requestDto)
  at ServiceStack.ServiceStackHost.ApplyRequestFilters(IRequest req, IResponse res, Object requestDto)
  at ServiceStack.Host.RestHandler.ProcessRequestAsync(IRequest httpReq, IResponse httpRes, String operationName)
 
2014-11-29 17:02:10.4317 Debug - HttpServer: HTTP Response 401 to 192.168.1.142. Response time: 1.0001 ms.
2014-11-29 17:02:14.1899 Info - App: StartupTrigger fired for task: Refresh Channels
2014-11-29 17:02:14.1899 Info - App: Executing Refresh Channels
2014-11-29 17:02:14.1899 Info - App: Refresh Channels Completed after 0 minute(s) and 0 seconds
2014-11-29 17:02:14.1899 Info - ServerManager: Sending web socket message ScheduledTaskEnded
2014-11-29 17:02:16.0980 Info - App: HttpClientManager GET: http://bot.whatismyipaddress.com/
2014-11-29 17:02:16.3450 Info - App: HttpClientManager POST: https://connect.mediabrowser.tv/service/Servers?id=97c6cc2160c0fe01bdb972d644752d6f
2014-11-29 17:02:21.3763 Debug - HttpServer: HTTP GET http://localhost:8096/mediabrowser/dashboard/support.html
Ip: 127.0.0.1:50644. Headers: Host=localhost:8096,Connection=keep-alive,Accept=text/html, */*; q=0.01,User-Agent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.71 Safari/537.36,DNT=1,Accept-Encoding=gzip, deflate, sdch,Accept-Language=en-US,en;q=0.8,If-None-Match=5dcb61fde26d33ea098dc23651f99647
2014-11-29 17:02:21.3763 Debug - HttpServer: HTTP Response 304 to 127.0.0.1. Response time: 0 ms.
2014-11-29 17:02:21.4713 Info - App: ActivityLogWebSocketListener Begin transmitting over websocket to 127.0.0.1:50654
2014-11-29 17:02:21.4713 Info - App: ActivityLogWebSocketListener stop transmitting over websocket to 127.0.0.1:50654
2014-11-29 17:02:21.4713 Info - App: SessionInfoWebSocketListener stop transmitting over websocket to 127.0.0.1:50654
2014-11-29 17:02:21.4713 Info - App: ScheduledTasksWebSocketListener stop transmitting over websocket to 127.0.0.1:50654
2014-11-29 17:02:22.4064 Debug - HttpServer: HTTP GET http://localhost:8096/mediabrowser/dashboard/log.html
Ip: 127.0.0.1:50644. Headers: Host=localhost:8096,Connection=keep-alive,Accept=text/html, */*; q=0.01,User-Agent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.71 Safari/537.36,DNT=1,Accept-Encoding=gzip, deflate, sdch,Accept-Language=en-US,en;q=0.8,If-None-Match=c245f3e314012c4a1222dc40241bbe6e
2014-11-29 17:02:22.4064 Debug - HttpServer: HTTP Response 304 to 127.0.0.1. Response time: 1 ms.
2014-11-29 17:02:22.4734 Debug - HttpServer: HTTP GET http://localhost:8096/mediabrowser/System/Logs
Ip: 127.0.0.1:50644. Headers: Host=localhost:8096,Connection=keep-alive,Accept=application/json, text/javascript, */*; q=0.01,X-MediaBrowser-Token=82a66102bbe84c65a7cd92926310c6d2,User-Agent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.71 Safari/537.36,Authorization=MediaBrowser Client="Dashboard", Device="Chrome 39.0.2171.71", DeviceId="6bbf4cbea905adc9251a53f1326816f3f5630114", Version="3.0.5445.5", UserId="9fcff9915f996d751b1b406eca2a44ea",DNT=1,Accept-Encoding=gzip, deflate, sdch,Accept-Language=en-US,en;q=0.8
2014-11-29 17:02:22.4904 Debug - HttpServer: HTTP Response 200 to 127.0.0.1. Response time: 17.001 ms.
Edited by wesbronco75
Link to comment
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
×
×
  • Create New...