Jump to content

Server process is not closing on restart or restart is attempted to soon


gthrift

Recommended Posts

gthrift

I woke up the past two mornings and have had to remote into my server to start the MB server because the restart had failed.  This log is where I manually hit the restart today to test it.

2014-04-30 10:20:35.3184 Debug - HttpServer: HTTP POST http://********:8096/mediabrowser/System/Restart
2014-04-30 10:20:35.3340 Debug - HttpServer: HTTP Response 204 to *************:55695. Response time: 15.5995 ms
	Url: http://***************:8096/mediabrowser/System/Restart
2014-04-30 10:20:35.4744 Info - Main: Disposing app host
2014-04-30 10:20:35.4744 Info - App: Disposing ApplicationHost
2014-04-30 10:20:35.4900 Info - App: Disposing TaskManager
2014-04-30 10:20:35.5056 Info - App: Disposing HttpClientManager
2014-04-30 10:20:35.5056 Info - App: Disposing InstallationManager
2014-04-30 10:20:35.5212 Info - App: Disposing IsoManager
2014-04-30 10:20:35.5212 Info - App: Disposing SqliteUserRepository
2014-04-30 10:20:35.6616 Info - App: Disposing SqliteDisplayPreferencesRepository
2014-04-30 10:20:35.6772 Info - App: Disposing SqliteItemRepository
2014-04-30 10:20:35.6928 Info - App: Disposing SqliteProviderInfoRepository
2014-04-30 10:20:35.6928 Info - App: Disposing LibraryMonitor
2014-04-30 10:20:35.7240 Debug - HttpServer: HTTP GET http://*************:8096/mediabrowser/System/Info
2014-04-30 10:20:35.7552 Info - App: Disposing ServerManager
2014-04-30 10:20:35.7708 Info - ServerManager: Disposing AlchemyServer
2014-04-30 10:20:35.7708 Warn - HttpServer: System.Net.HttpListenerException (0x80004005): The I/O operation has been aborted because of either a thread exit or an application request
   at System.Net.HttpListener.EndGetContext(IAsyncResult asyncResult)
   at MediaBrowser.Server.Implementations.HttpServer.HttpListenerHost.ListenerCallback(IAsyncResult asyncResult, Int32 index): False
2014-04-30 10:20:35.7708 Debug - App: Disposing alchemy server
2014-04-30 10:20:35.8020 Info - App: Disposing MediaEncoder
2014-04-30 10:20:35.8020 Info - App: Disposing ImageProcessor
2014-04-30 10:20:35.8176 Info - App: Disposing ContentDirectory
2014-04-30 10:20:35.8176 Info - App: Disposing LiveTvManager
2014-04-30 10:20:35.8332 Info - App: Disposing MovieDbProvider
2014-04-30 10:20:35.8488 Info - App: Disposing PismoIsoManager
2014-04-30 10:20:35.8488 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:35.8644 Info - App: Disposing AutomaticRestartEntryPoint
2014-04-30 10:20:35.8644 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:35.8800 Info - App: Disposing ExternalPortForwarding
2014-04-30 10:20:35.8800 Debug - App: Stopping NAT discovery
2014-04-30 10:20:35.8956 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:35.8956 Info - App: Disposing LibraryChangedNotifier
2014-04-30 10:20:35.8956 Error - HttpServer: ProcessRequest failure
	ServiceStack: AppHost does not exist or has not been initialized. Make sure you have created an AppHost and started it with 'new AppHost().Init();'  in your Global.asax Application_Start() or alternative Application StartUp
	System.Configuration.ConfigurationErrorsException
	   at ServiceStack.HostContext.AssertAppHost()
	   at ServiceStack.Host.RestHandler.ProcessRequestAsync(IRequest httpReq, IResponse httpRes, String operationName)
	   at MediaBrowser.Server.Implementations.HttpServer.HttpListenerHost.ProcessRequestAsync(HttpListenerContext context)
	   at MediaBrowser.Server.Implementations.HttpServer.HttpListenerHost.<>c__DisplayClasse.<<ListenerCallback>b__d>d__10.MoveNext()
	
2014-04-30 10:20:35.9112 Info - App: Disposing LocalMovieThemeVideoEntryPoint
2014-04-30 10:20:35.9112 Error - HttpServer: Error this.ProcessRequest(context)(Exception while writing error to the response)
	ServiceStack: AppHost does not exist or has not been initialized. Make sure you have created an AppHost and started it with 'new AppHost().Init();'  in your Global.asax Application_Start() or alternative Application StartUp
	System.Configuration.ConfigurationErrorsException
	   at ServiceStack.HostContext.AssertAppHost()
	   at ServiceStack.HttpRequestExtensions.GetAttributes(IRequest request)
	   at MediaBrowser.Server.Implementations.HttpServer.HttpListenerHost.HandleError(Exception ex, HttpListenerContext context, ILogger logger)
	
2014-04-30 10:20:35.9268 Info - App: Disposing LoadRegistrations
2014-04-30 10:20:35.9268 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:35.9424 Info - App: Disposing Notifications
2014-04-30 10:20:35.9580 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:35.9580 Info - App: Disposing RemoteNotifications
2014-04-30 10:20:35.9736 Info - App: Disposing ServerMediator
2014-04-30 10:20:35.9736 Info - App: Disposing WebSocketNotifier
2014-04-30 10:20:35.9892 Info - App: Disposing LocalYTrailersEntryPoint
2014-04-30 10:20:35.9892 Info - App: Disposing RefreshUsersMetadata
2014-04-30 10:20:36.0048 Info - App: Disposing ApiEntryPoint
2014-04-30 10:20:36.0048 Info - App: Disposing UsageEntryPoint
2014-04-30 10:20:36.0204 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:36.0204 Info - App: Disposing UdpServerEntryPoint
2014-04-30 10:20:36.0360 Info - App: Disposing ServerEventNotifier
2014-04-30 10:20:36.0360 Info - App: Disposing UserDataChangeNotifier
2014-04-30 10:20:36.0516 Info - App: Disposing NewsEntryPoint
2014-04-30 10:20:36.0516 Info - App: Disposing DlnaEntryPoint
2014-04-30 10:20:36.0828 Debug - Dlna: Unregistered mount 30d1f926-ae32-80b3-c931-22fc3d130de7
2014-04-30 10:20:36.0828 Debug - Dlna: Stopping alive notifier
2014-04-30 10:20:36.0984 Info - App: Disposing ResourceEntryPoint
2014-04-30 10:20:36.1140 Info - App: Disposing StartupWizard
2014-04-30 10:20:36.1140 Info - App: Disposing WanAddressEntryPoint
2014-04-30 10:20:36.1296 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:36.1296 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:36.1452 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:36.1452 Info - App: Disposing LocalMovieThemeVideoEntryPoint
2014-04-30 10:20:36.1608 Info - App: Disposing ServerEntryPoint
2014-04-30 10:20:36.1608 Info - Main: Executing windows forms restart
2014-04-30 10:20:36.5352 Info - Main: Shutting down
2014-04-30 10:20:36.5352 Info - App: Disposing ApplicationHost

Restart Attempt

2014-04-30 10:20:36.9720 Info - Main: Media Browser Server started
2014-04-30 10:20:37.0032 Info - Main: Command line: C:\Users\Administrator\AppData\Roaming\MediaBrowser-Server\System\MediaBrowser.ServerApplication.exe
2014-04-30 10:20:37.0188 Info - Main: Server: SERVER
2014-04-30 10:20:37.0188 Info - Main: Operating system: Microsoft Windows NT 6.1.7601 Service Pack 1
2014-04-30 10:20:37.0344 Info - Main: Program data path: C:\Users\Administrator\AppData\Roaming\MediaBrowser-Server
2014-04-30 10:20:37.0344 Info - Main: Application Path: C:\Users\Administrator\AppData\Roaming\MediaBrowser-Server\System\MediaBrowser.ServerApplication.exe
2014-04-30 10:20:37.0656 Info - Main: Found a duplicate process. Giving it time to exit.
2014-04-30 10:20:42.3226 Info - Main: The duplicate process did not exit.
2014-04-30 10:20:42.3226 Info - Main: Shutting down because another instance of Media Browser Server is already running.

Manual Attempt

2014-04-30 10:21:42.7551 Info - Main: Media Browser Server started
2014-04-30 10:21:42.7863 Info - Main: Command line: C:\Users\Administrator\AppData\Roaming\MediaBrowser-Server\System\MediaBrowser.ServerApplication.exe
2014-04-30 10:21:42.8019 Info - Main: Server: SERVER
2014-04-30 10:21:42.8019 Info - Main: Operating system: Microsoft Windows NT 6.1.7601 Service Pack 1
2014-04-30 10:21:42.8019 Info - Main: Program data path: C:\Users\Administrator\AppData\Roaming\MediaBrowser-Server
2014-04-30 10:21:42.8019 Info - Main: Application Path: C:\Users\Administrator\AppData\Roaming\MediaBrowser-Server\System\MediaBrowser.ServerApplication.exe
2014-04-30 10:21:42.8331 Info - Main: Found a duplicate process. Giving it time to exit.
2014-04-30 10:21:47.8405 Info - Main: The duplicate process did not exit.
2014-04-30 10:21:47.8405 Info - Main: Shutting down because another instance of Media Browser Server is already running.

2nd Manual Attempt 

2014-04-30 10:22:48.0078 Info - Main: Media Browser Server started
2014-04-30 10:22:48.0390 Info - Main: Command line: C:\Users\Administrator\AppData\Roaming\MediaBrowser-Server\System\MediaBrowser.ServerApplication.exe
2014-04-30 10:22:48.0546 Info - Main: Server: SERVER
2014-04-30 10:22:48.0546 Info - Main: Operating system: Microsoft Windows NT 6.1.7601 Service Pack 1
2014-04-30 10:22:48.0546 Info - Main: Program data path: C:\Users\Administrator\AppData\Roaming\MediaBrowser-Server
2014-04-30 10:22:48.0702 Info - Main: Application Path: C:\Users\Administrator\AppData\Roaming\MediaBrowser-Server\System\MediaBrowser.ServerApplication.exe
2014-04-30 10:22:49.0685 Info - App: Application Configuration:

It's taking about two or so minutes to kill the process.  In that time the automatic restart fails and I then have to do it manually.

 

 

Running Version 3.0.5231.40980

 

This started after the last update.

Edited by gthrift
Link to comment
Share on other sites

Happy2Play

I see the exact same thing on current 3.0.5238.39498 and previous version.  Doesn't matter whether service or Manual running program.

  • Like 1
Link to comment
Share on other sites

  • 1 month later...
kfonda

I've been having this problem for the last few beta versions. I'm currently running Version 3.0.5271.29451 on Windows Server 2012 R2 Essentials. Did you guys come up with a solution for this?

Link to comment
Share on other sites

Koleckai Silvestri

I have this problem when I got impatient and tried to manually start after doing a restart sequence. Some seem to take a while in the shutdown tasks but the icon is removed from the tray before it actually shuts down. I simply try to be more patient now.

Link to comment
Share on other sites

if you guys could post shutdown logs using the new server release that would be helpful. and complete logs, not snippets, thanks.

Link to comment
Share on other sites

Good day,

 

I see it as well some times, not all the times, like when updating 2 to 3 plugins at once and restart, I see it. I do not know if this the same issue or not, but will provide a log when I see it next time.

 

My best

Link to comment
Share on other sites

kfonda

@@Luke

 

Did you get a chance to look at the log files? I had to restart again yesterday and this time I clicked on 'exit' from the tray icon and watched it in task manager. It took just over 1 minute to shut down if that helps. Is there anything I can do to help fix it?

Link to comment
Share on other sites

Happy2Play

Is it safe to assume I'm on my own with this one?

No your not the only one that sees this.

Link to comment
Share on other sites

kfonda

@@Luke

 

what you guys can do in the meantime is collect info the next time it happens

 

- are any users watching content? If so, are any transcoding?

- Are there any scheduled tasks running?

- Are there any open ffmpeg or ffprobe processes?

 

It happens every time I try to restart the server.

Only connection to server is me connected to Dashboard.

No tasks running.

No ffmpeg or ffprobe processes running.

 

I tried removing all plugins and it still take between 1 and 2 minutes to shutdown.

Link to comment
Share on other sites

kfonda

Just for information purposes. This still happens in the new 3.0.5287 Beta version.

Link to comment
Share on other sites

Just for information purposes. This still happens in the new 3.0.5287 Beta version.

 

Please post a pair of new server logs. Thanks.

Link to comment
Share on other sites

muehlberger

Just a few more bits I noticed - they are maybe helpful ...

 

  • I've the same problem and it seems they started when I started using nextPVR & the corresponding plugin. I'm not quite 100% sure, but maybe it's a hint
  • When closing the server, the process keeps running with constant memory usage and no cpu usage. What's interesting is, that you can't kill the process even with admin rights

 

-- muehlberger

Link to comment
Share on other sites

  • 1 month later...
kfonda

@@Luke The last batch of updates seems to have solved the restarting problem that I was having. I turned on "allow server to restart automatically" in advanced settings and it is working as it should now.

 

Thanks for fixing this and keep on steaming ahead, you guys are moving at a ridiculously fast pace. :-)

Link to comment
Share on other sites

  • 5 months later...
  • 5 months later...
  • 2 weeks later...

I have been having this issue for a while now also.

 

I just had to manually start Emby today when I notice it was down.   It had failed to restart on its own in the night due to duplicate process (last 3 logs of the night it failed to restart, are attached).  

 

I am currently running: 3.0.5667.6

Version that failed to restart according to attached logs:  3.0.5666.8

I have turned off IPV6 on the server, due to other hangs on update of plugins issue.

I only auto update to level of "Official Release"

 

server-63572349532.txtserver-63572349545.txtserver-63572349859.txt

 

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...