Post Wed Jun 04, 2014 5:19 am

Serviio randomly crashes on NAS

I have Serviio 1.4 installed on a Synology DS209 NAS. When Serviio is running, everything works fine. However, Serviio crashes after running for minutes to days. It seems random, I can't correlate it to any other time/action. I leave my NAS running all the time. The library is set to refresh once a day. I've turned on DEBUG logging for both Serviio and JCS. The only consistent problems I see around the crash are these warnings:

  Code:
WARN  [IndexedDiskCache] Region [online_technical_metadata] Disk cache not shutdown properly, shutting down now.
WARN  [IndexedDiskCache] Region [tokens] Disk cache not shutdown properly, shutting down now.
WARN  [IndexedDiskCache] Region [thumbnails] Disk cache not shutdown properly, shutting down now.


Here's a more complete log snippet. The whole log is very large since I have many DEBUGs turned on, but let me know if you want to see it.

  Code:
2014-06-02 00:00:15,699 DEBUG [SearchManager] Committing search index
2014-06-02 00:00:26,792 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.0.123:5030s
2014-06-02 00:00:26,793 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.0.123:5030s
2014-06-02 00:00:26,794 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.0.123:5030
2014-06-02 00:00:26,795 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.0.123:5030
2014-06-02 00:00:45,709 DEBUG [SearchManager] Committing search index
2014-06-02 00:01:05,789 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2014-06-02 00:01:05,789 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2014-06-02 00:01:15,719 DEBUG [SearchManager] Committing search index
2014-06-02 00:01:21,053 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.0.123:5030s
2014-06-02 00:01:21,054 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.0.123:5030
2014-06-02 00:01:21,055 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.0.123:5030s
2014-06-02 00:01:21,071 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.0.123:5030
2014-06-02 00:01:45,729 DEBUG [SearchManager] Committing search index
2014-06-02 00:02:05,799 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2014-06-02 00:02:05,799 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2014-06-02 00:02:14,962 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.0.123:5030s
2014-06-02 00:02:14,963 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.0.123:5030s
2014-06-02 00:02:14,964 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.0.123:5030
2014-06-02 00:02:14,965 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.0.123:5030
2014-06-02 00:02:15,739 DEBUG [SearchManager] Committing search index
2014-06-02 00:02:45,749 DEBUG [SearchManager] Committing search index
2014-06-02 00:03:01,059 DEBUG [PlaylistDAOImpl] Reading all Playlists
2014-06-02 00:03:05,809 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2014-06-02 00:03:05,809 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2014-06-02 00:03:09,222 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.0.123:5030s
2014-06-02 00:03:09,223 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.0.123:5030
2014-06-02 00:03:09,224 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.0.123:5030s
2014-06-02 00:03:09,225 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.0.123:5030
2014-06-02 00:03:15,759 DEBUG [SearchManager] Committing search index
2014-06-02 00:03:38,390 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface eth0 (eth0) and address 192.168.0.2, timeout = 0
2014-06-02 00:03:38,391 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device c41c5514-0d79-3774-967b-023b9e31d01f
2014-06-02 00:03:40,369 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:03:39 (advertisement duration is 1800 sec.)
2014-06-02 00:03:40,494 WARN  [IndexedDiskCache] Region [thumbnails] Disk cache not shutdown properly, shutting down now.
2014-06-02 00:03:40,506 INFO  [LibraryAdditionsCheckerThread] Finished looking for newly added files
2014-06-02 00:03:40,506 INFO  [LibraryUpdatesCheckerThread] Finished looking for updates to currently shared files
2014-06-02 00:03:40,507 INFO  [FeedUpdaterThread] Finished looking for online resources information
2014-06-02 00:03:40,509 WARN  [IndexedDiskCache] Region [tokens] Disk cache not shutdown properly, shutting down now.
2014-06-02 00:03:40,495 WARN  [IndexedDiskCache] Region [online_technical_metadata] Disk cache not shutdown properly, shutting down now.
2014-06-02 00:03:40,620 INFO  [SearchIndexer] Closing search index writer
2014-06-02 00:03:40,757 INFO  [SearchIndexer] Closing search index writer
2014-06-02 00:03:40,814 DEBUG [WebServer] Socket closed
2014-06-02 00:03:40,814 INFO  [WebServer] WebServer shutting down
2014-06-02 00:03:40,814 DEBUG [DiscoveryManager] UPNP device c41c5514-0d79-3774-967b-023b9e31d01f (192.168.0.2) is unavailable
2014-06-02 00:03:40,815 INFO  [DiscoveryAdvertisementNotifier] Leaving DiscoveryAdvertisementNotifier
2014-06-02 00:03:40,817 DEBUG [DiscoverySSDPMessageListener] Socket closed: Socket closed
<repeats many times>
2014-06-02 00:03:40,829 DEBUG [DiscoverySSDPMessageListener] Socket closed: Socket closed
2014-06-02 00:03:40,829 INFO  [EventSubscriptionExpirationChecker] Leaving EventSubscriptionExpirationChecker, removing all event subscriptions
2014-06-02 00:03:40,830 DEBUG [EventSubscriptionExpirationChecker] Removed subscription f0d2ddc6-06c3-4db8-bad9-fc4b636aef26 from service urn:upnp-org:serviceId:ConnectionManager
2014-06-02 00:03:40,830 DEBUG [EventSubscriptionExpirationChecker] Removed subscription bed2b51c-3ee3-4823-9bfe-de10354f6ed5 from service urn:upnp-org:serviceId:ContentDirectory
2014-06-02 00:03:40,831 INFO  [EventDispatcher] Leaving EventDispatcher
2014-06-02 00:03:40,850 DEBUG [DiscoverySSDPMessageListener] Socket closed: Socket closed
2014-06-02 00:03:40,850 INFO  [DiscoverySSDPMessageListener] Leaving DiscoverySSDPMessageListener
2014-06-02 00:03:40,852 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP byebye using interface eth0 (eth0) and address 192.168.0.2, timeout = 0
2014-06-02 00:03:40,856 INFO  [DatabaseManager] Shutting down database
2014-06-02 00:03:40,858 DEBUG [DBConnectionPool] Closed connection for pool Serviio DB Pool
2014-06-02 00:03:40,859 DEBUG [DBConnectionPool] Closed connection for pool Serviio DB Pool
2014-06-02 00:03:40,860 DEBUG [DBConnectionPool] Closed connection for pool Serviio DB Pool
2014-06-02 00:03:42,078 DEBUG [DatabaseManager] DB shutdown returned: Derby system shutdown.
2014-06-02 00:03:42,078 INFO  [AbstractTranscodingDeliveryEngine] Cleaning transcode engine and its data


I had similar problems after my initial install. Had some error messages related to playlists so I removed all those and that seemed to make it happy, ran for weeks+ at a time. The problem started again after I deleted (renamed) my old library and started a new library. I can force a refresh via Serviio Console and that works fine. Like I said, at times it will stay up for a couple of days, but other times it'll die after a few minutes.