Sonarr - Unraid stops running

duckman · July 28, 2015, 12:56pm

Running sonarr, latest version, via PhaZe’ UnRAID plugin. Unraid 5.06

After a huge amount of work importing my existing series into sonarr, I got up this morning to find it wasn’t running. I checked the plugin; status was STOPPED. I restarted it. It began refreshing series, and all looked normal. After about 5 minutes, “connection with backend lost” I checked again- again “STOPPED” at which point, I left it stopped, restarted Sickbeard- because I have no idea how long sonarr had been dead-in-the-water. And shows wait for no one.

And here I am…

Are there any sort of logs that can help you troubleshoot what’s happening?

The only things I can report- During the restart, I DID see a dialog box that said sonarr was either applying an update or that it HAD APPLIED an update. AND I did notice that in calendar view, all my shows were listed twice.

markus101 · July 28, 2015, 2:50pm

Not sure where log files are in that unRAID plugin, but definitely logs. Not sure what OS that docker is running, but Native mono crashes [kernel fix released] might be relevant.

duckman · July 28, 2015, 3:43pm

It isn’t a docker, it’s a plug-in. (I’m still using UnRAID 5.06; no docker support). So the O/S is Slackware Linux. I saw 3/4 log files this morning. Only one had today’s date, and when I opened it in notepad, it was a solid wall of text; no linefeeds, c/r…just a WALL of text. Not the sort of content I’d want to post in a public forum, but would be happy to submit to the dev(s) privately. FWIW: The plugin was working for the past few days- only bombing last night/today. (Yesterday, I made the final push, adding the remainder of my shows) It was a significant increase- not sure how my count stacks up against your typical sonarr user.

UPDATE: I was incorrect- the log file only looks that way in Notepad. In WordPad, it’s a much more readable LOG.

duckman · July 28, 2015, 4:51pm

I decided to restart sonarr- thinking this morning’s shutdown was related to the ‘update’ notification. I turned off Sickbeard, and restarted sonarr at 12:27. It ran fine until 12:39, at which point, it shut down again. I checked the log file, and whatever it’s doing, it isn’t simply ‘crashing’ It’s making log entries right up until the end.

The last few entries, immediately after it’s finished scanning for shows

15-7-28 12:39:32.9|Info|Bootstrap|Starting Sonarr - /usr/local/Sonarr/NzbDrone.exe - Version 2.0.0.3357
15-7-28 12:39:33.7|Info|MigrationLogger|*** Migrating data source=/.config/NzbDrone/nzbdrone.db;cache size=-10485760;datetimekind=Utc;journal mode=Wal;pooling=True;version=3 ***
15-7-28 12:39:34.0|Debug|MigrationLogger|Took: 00:00:00.3491484
15-7-28 12:39:34.0|Info|MigrationLogger|*** Migrating data source=/.config/NzbDrone/logs.db;cache size=-10485760;datetimekind=Utc;journal mode=Wal;pooling=True;version=3 ***
15-7-28 12:39:34.1|Debug|MigrationLogger|Took: 00:00:00.0228534
15-7-28 12:39:34.2|Info|Router|Application mode: Help
15-7-28 12:39:34.3|Info|ConsoleApp|Exiting main.

markus101 · July 28, 2015, 7:11pm

Sonarr was started up to check the start arguments,

Sonarr will log that if you start it with a couple different switches (looking for information on which parameters are available), that doesn’t happen automatically though. Someone or something is relaunching Sonarr by the looks of it.

Turn on ((trace logging)) to see more details, but the current logs are very suspicious (though again, nothing Sonarr would do on its own).

duckman · July 28, 2015, 8:00pm

Same scenario. Stopped Sickbeard. Started Sonarr. It ran for a few minutes before stopping.

Basically the same closing lines in the log- which was swelling fast.

15-7-28 15:47:01.1|Debug|Parser|Quality parsed: DVD v1
15-7-28 15:47:01.1|Debug|Parser|Release Group parsed: SNOW
15-7-28 15:47:46.2|Info|Bootstrap|Starting Sonarr - /usr/local/Sonarr/NzbDrone.exe - Version 2.0.0.3357
15-7-28 15:47:46.9|Info|MigrationLogger|*** Migrating data source=/.config/NzbDrone/nzbdrone.db;cache size=-10485760;datetimekind=Utc;journal mode=Wal;pooling=True;version=3 ***
15-7-28 15:47:47.3|Debug|MigrationLogger|Took: 00:00:00.3633071
15-7-28 15:47:47.3|Info|MigrationLogger|*** Migrating data source=/.config/NzbDrone/logs.db;cache size=-10485760;datetimekind=Utc;journal mode=Wal;pooling=True;version=3 ***
15-7-28 15:47:47.3|Debug|MigrationLogger|Took: 00:00:00.0218869
15-7-28 15:47:47.4|Info|Router|Application mode: Help
15-7-28 15:47:47.5|Info|ConsoleApp|Exiting main.

Figuring this might not be helpful, I looked on up in the log and noticed a segment which WASN’T formatted the same- no time/date stamp. Hope this helps…I included a few lines before/after for context. Thanks for the continued attention.

15-7-28 15:46:55.6|Debug|DiskScanService|Scanning '/mnt/user/TV/The Cell' for video files
15-7-28 15:46:55.7|Trace|Parser|^(?<title>.+?)(?:(?:[-_\W](?<![()\[!]))+S?(?<season>(?<!\d+)(?:\d{1,2}|\d{4})(?!\d+))(?:[ex]|\W[ex]|_){1,2}(?<episode>\d{2,3}(?!\d+))(?:(?:\-|[ex]|\W[ex]|_){1,2}(?<episode>\d{2,3}(?!\d+)))*)\W?(?!\\)
15-7-28 15:46:55.7|Debug|GlobalExceptionHandlers|Minor Fail: An exception was thrown by the type initializer for System.Drawing.GDIPlus

System.TypeInitializationException: An exception was thrown by the type initializer for System.Drawing.GDIPlus ---> System.DllNotFoundException: libgdiplus.so
  at (wrapper managed-to-native) System.Drawing.GDIPlus:GdiplusStartup (ulong&,System.Drawing.GdiplusStartupInput&,System.Drawing.GdiplusStartupOutput&)
  at System.Drawing.GDIPlus..cctor () [0x00000] in <filename unknown>:0 
  --- End of inner exception stack trace ---
  at System.Drawing.Image.InitFromStream (System.IO.Stream stream) [0x00000] in <filename unknown>:0 
  at System.Drawing.Bitmap..ctor (System.IO.Stream stream, Boolean useIcm) [0x00000] in <filename unknown>:0 
  at (wrapper remoting-invoke-with-check) System.Drawing.Bitmap:.ctor (System.IO.Stream,bool)
  at ImageResizer.ImageBuilder.DecodeStream (System.IO.Stream s, ImageResizer.ResizeSettings settings, System.String optionalPath) [0x00000] in <filename unknown>:0 
  at ImageResizer.ImageBuilder.LoadImage (System.Object source, ImageResizer.ResizeSettings settings, Boolean restoreStreamPos) [0x00000] in <filename unknown>:0 

15-7-28 15:46:55.7|Debug|Parser|Episode Parsed. Supernatural - S04E15 
15-7-28 15:46:55.7|Debug|GlobalExceptionHandlers|Minor Fail: An exception was thrown by the type initializer for System.Drawing.GDIPlus

System.TypeInitializationException: An exception was thrown by the type initializer for System.Drawing.GDIPlus ---> System.DllNotFoundException: libgdiplus.so
  at (wrapper managed-to-native) System.Drawing.GDIPlus:GdiplusStartup (ulong&,System.Drawing.GdiplusStartupInput&,System.Drawing.GdiplusStartupOutput&)
  at System.Drawing.GDIPlus..cctor () [0x00000] in <filename unknown>:0 
  --- End of inner exception stack trace ---
  at System.Drawing.Image.InitFromStream (System.IO.Stream stream) [0x00000] in <filename unknown>:0 
  at System.Drawing.Bitmap..ctor (System.IO.Stream stream, Boolean useIcm) [0x00000] in <filename unknown>:0 
  at (wrapper remoting-invoke-with-check) System.Drawing.Bitmap:.ctor (System.IO.Stream,bool)
  at ImageResizer.ImageBuilder.DecodeStream (System.IO.Stream s, ImageResizer.ResizeSettings settings, System.String optionalPath) [0x00000] in <filename unknown>:0 
  at ImageResizer.ImageBuilder.LoadImage (System.Object source, ImageResizer.ResizeSettings settings, Boolean restoreStreamPos) [0x00000] in <filename unknown>:0 

15-7-28 15:46:55.7|Debug|DiskScanService|3 video files were found in /mnt/user/TV/The Cell
15-7-28 15:46:55.7|Debug|Parser|Language parsed: English
15-7-28 15:46:55.7|Trace|EventAggregator|MediaCoversUpdatedEvent <- MetadataService
15-7-28 15:46:55.7|Debug|GlobalExceptionHandlers|Minor Fail: An exception was thrown by the type initializer for System.Drawing.GDIPlus

System.TypeInitializationException: An exception was thrown by the type initializer for System.Drawing.GDIPlus ---> System.DllNotFoundException: libgdiplus.so
  at (wrapper managed-to-native) System.Drawing.GDIPlus:GdiplusStartup (ulong&,System.Drawing.GdiplusStartupInput&,System.Drawing.GdiplusStartupOutput&)
  at System.Drawing.GDIPlus..cctor () [0x00000] in <filename unknown>:0 
  --- End of inner exception stack trace ---
  at System.Drawing.Image.InitFromStream (System.IO.Stream stream) [0x00000] in <filename unknown>:0 
  at System.Drawing.Bitmap..ctor (System.IO.Stream stream, Boolean useIcm) [0x00000] in <filename unknown>:0 
  at (wrapper remoting-invoke-with-check) System.Drawing.Bitmap:.ctor (System.IO.Stream,bool)
  at ImageResizer.ImageBuilder.DecodeStream (System.IO.Stream s, ImageResizer.ResizeSettings settings, System.String optionalPath) [0x00000] in <filename unknown>:0 
  at ImageResizer.ImageBuilder.LoadImage (System.Object source, ImageResizer.ResizeSettings settings, Boolean restoreStreamPos) [0x00000] in <filename unknown>:0 

15-7-28 15:46:55.7|Trace|DiskScanService|Finished getting episode files for: [109171][The Cell] [00:00:00.0185403]
15-7-28 15:46:55.7|Debug|NzbDrone.Core.Parser.QualityParser|Trying to parse quality for Supernatural.S04E15.Death.Takes.A.Holiday.BDRip.XviD-SAiNTS
15-7-28 15:46:55.7|Trace|EventAggregator|MediaCoversUpdatedEvent -> SeriesModule
15-7-28 15:46:55.7|Debug|DiskScanService|[109171][The Cell] Cleaning up media files in DB
15-7-28 15:46:55.7|Debug|GlobalExceptionHandlers|Minor Fail: An exception was thrown by the type initializer for System.Drawing.GDIPlus

System.TypeInitializationException: An exception was thrown by the type initializer for System.Drawing.GDIPlus ---> System.DllNotFoundException: libgdiplus.so
  at (wrapper managed-to-native) System.Drawing.GDIPlus:GdiplusStartup (ulong&,System.Drawing.GdiplusStartupInput&,System.Drawing.GdiplusStartupOutput&)
  at System.Drawing.GDIPlus..cctor () [0x00000] in <filename unknown>:0 
  --- End of inner exception stack trace ---
  at System.Drawing.Image.InitFromStream (System.IO.Stream stream) [0x00000] in <filename unknown>:0 
  at System.Drawing.Bitmap..ctor (System.IO.Stream stream, Boolean useIcm) [0x00000] in <filename unknown>:0 
  at (wrapper remoting-invoke-with-check) System.Drawing.Bitmap:.ctor (System.IO.Stream,bool)
  at ImageResizer.ImageBuilder.DecodeStream (System.IO.Stream s, ImageResizer.ResizeSettings settings, System.String optionalPath) [0x00000] in <filename unknown>:0 
  at ImageResizer.ImageBuilder.LoadImage (System.Object source, ImageResizer.ResizeSettings settings, Boolean restoreStreamPos) [0x00000] in <filename unknown>:0 

15-7-28 15:46:55.7|Debug|Parser|Quality parsed: DVD v1
15-7-28 15:46:55.7|Debug|Parser|Release Group parsed: SAiNTS
15-7-28 15:46:55.7|Debug|ImportDecisionMaker|Analyzing 0/3 files.

markus101 · July 28, 2015, 11:03pm

Those lines are exception stack traces, which come from the line above it. They just indicate that Sonarr can’t resize images, but they shouldn’t cause any issues and definitely wouldn’t cause Sonarr to restart in help mode.

On the general settings page, turn advanced settings on then take a look at the update section, could you post a screen shot of that section?

duckman · July 28, 2015, 11:15pm

Here ya go.

markus101 · July 28, 2015, 11:16pm

Anything else under updates?

duckman · July 28, 2015, 11:25pm

Two lines:

Automatic: OFF

mechanism: BUILT IN

markus101 · July 29, 2015, 12:37am

Okay, I just wanted to rule out a custom update script doing something weird (not likely, but tough to say).

I’m running out of ideas here, nothing within Sonarr would start itself with the the ? flag (to end up logging the message seen at the end of the logs). Clear the existing logs, start Sonarr and then hastbin the full log? If its too big/spans multiple files a link to grab a zip from Dropbox (or similar would be great).

duckman · July 29, 2015, 1:35am

I’ve been communicating concurrently with the plugin author. After reviewing a screenshot of my system’s memory status via a TOP command, he feels I’m probably running out of RAM. Server has 8Gb, but only about 1Gb free… I’m guessing sabnzbd/cache-dirs/PLEX/ and Sonarr are bumping elbows- which didn’t become an issue until juggling several hundred TV series. Others in the house are watching TV (plus I’m an old rooster, ready to sleep, myself)…so I’ll pick this up tomorrow and get back to you. Thanks again for all the follow-ups. I really DO like Sonarr.

PS: For the future, please consider adding the number of episodes ##/## column to the ‘series editor’ screen. After importing all my series, I had countless series that are marked as being monitored, but which have ended…AND I have ALL the episodes already. Being able to go into ‘series editor’ and simply selecting ‘ended’, then going down the line, selecting all the series with green 125/125 status (for example) bar and toggling MONITORED…would be sooooo much easier than going one-by-one in the ‘series’ screen and selecting the ‘edit series’ wrench for each series showing ‘ended’ with all episodes present.

markus101 · July 29, 2015, 1:54am

Okay, keep me posted.

Actually you can view that information on Season Pass, which is meant for altering monitoring. Right now I believe the monitored toggle for a series is missing, but will be in the next release and will also mean the end of toggle monitored status from series editor.

PhAzE · July 30, 2015, 6:00am

Hi, I’m the unraid plugin dev. I just wanted to point out that when a user goes to the plugin settings page it runs sonarr with help to grab the version number for the plugin settings page to display. That’s why you see that last line on the logs, the user goes to the plugin settings page to see that it is stopped and the app is then polled.

markus101 · July 30, 2015, 3:27pm

Thanks for the info @PhAzE

Which version of mono is included with this package?

duckman · July 30, 2015, 6:11pm

According to the status page: mono 3.8.0 sqlite 3.7.5 mediainfo 0.7.46 and curl 7.21.4

markus101 · July 30, 2015, 7:29pm

3.8 should be fine, though I can’t recall offhand if it had any known issues to us.

A couple possible reasons for crashing:

mono is dying for some reason
Image resizing failing and causing it to fail (even though we do what we can to prevent this)

In both cases standard output and standard error logs would be the best thing to look at since an error written when Sonarr is dead means its logging won’t pick it up.

duckman · July 30, 2015, 7:47pm

I’ll turn off trace and repeat the process.

markus101 · July 31, 2015, 5:37pm

Its not trace logs that I’m worried about, since those show the most detail to tell us what Sonarr is doing, but looking for the actual console output of Sonarr, which would show us mono level errors (that we can’t capture). I looked at the logs from today and didn’t see anything that indicates that something in Sonarr failed, so I want to see if mono is logging anything.

Two ways to get this output, redirect the console stdout and stderr to a file or just run mono in a console window, I’m not sure how to achieve either on unRAID though, maybe @PhAzE can help us here.

duckman · August 1, 2015, 8:03pm

I’m pulling a complete Homer Simpson over what you’ve just said. I’ll copy the message to Phaze on the UnRAID forum and see if he has anything to add. (Going on the theory that it’s a RAM issue, I’m not too worried long-term. He’s introducing a set of plugins whose dependencies are kept on a drive, rather than in RAM. In a few weeks, it may be a moot point.) Still, any dialogue between you two can only benefit users.