P3 beta testing feedback

[panteragstk]

Originally Posted by bialio

I guess a log from after removing the SageTVPluginsDev.xml file would be good.

What is the main issue you are seeing?

Media scanning isn't picking up new media and is only lasting about a second before stopping.

[bialio]

Is this new imported media? Like stuff that you've ripped to MKV or something recently?

(As opposed to new recordings)

[bialio]

I'm no linux guru. But in the log it looks like something is going through this path :

/var/media/external/*

and trying to mount every directory it finds there

Tue 11/15 14:21:56.047 [HotplugStorage@3e058b] Setup dir for external device mount: /var/media/external/sdc1
Tue 11/15 14:21:56.047 [HotplugStorage@3e058b] Executing process: [sh, -c, mount  | grep -i "/var/media/external/sdc1 type"]
Tue 11/15 14:21:56.047 [HotplugStorage@3e058b] Started process object: java.lang.UNIXProcess@b16ce3e
Tue 11/15 14:21:56.050 [HotplugStorage@3e058b] Executing process: [mount, /dev/sdc1, /var/media/external/sdc1, -o, noatime]
Tue 11/15 14:21:56.051 [HotplugStorage@3e058b] Started process object: java.lang.UNIXProcess@f37490b
Tue 11/15 14:21:56.051 [ErrorStreamConsumer@32e5d284] STDERR:java.lang.UNIXProcess@f37490b: mount: only root can use "--options" option
Tue 11/15 14:21:56.052 [HotplugStorage@3e058b] Executing process: [mount, /dev/sdc1, /var/media/external/sdc1]
Tue 11/15 14:21:56.052 [HotplugStorage@3e058b] Started process object: java.lang.UNIXProcess@4a429bd
Tue 11/15 14:21:56.053 [ErrorStreamConsumer@6a774325] STDERR:java.lang.UNIXProcess@4a429bd: mount: only root can do that
Tue 11/15 14:21:56.053 [HotplugStorage@3e058b] Failed mounting

and evidently failing because of not being root.

[bialio]

So given that - what is the path to the new media files that you are adding?

[panteragstk]

Originally Posted by bialio

So given that - what is the path to the new media files that you are adding?

It is a different path than that. Those have been there since I started using the unraid docker. I'm not sure why or what they are for though.

My path is /var/mediaext/tv shows

That is where all the stuff from play later records to as well as downloaded mkv files. They were showing up without issue, but just suddenly stopped.

[bialio]

I don't see anything obviously wrong in the log. There are 5 files that seem to give the LibraryImporter fits :

/var/recorded_tv_1/Nashville-S02E14-TooFarGone-14885336-0.mpg
/var/recorded_tv_1/TheOriginals-S03E17-21139343-0.ts
/var/recorded_tv_2/Gotham-S01E17-RedHood-17954420-0.mpg 
/var/recorded_tv_4/Hannibal-TheWrathoftheLamb-19609123-0.mpg
/var/recorded_tv_4/TheOriginals-AshestoAshes-18786100-0.mpg

It has errors on them every time. But I can't say that's what's causing the normal library scan to fail...

[jusjoken]

Originally Posted by panteragstk

It is a different path than that. Those have been there since I started using the unraid docker. I'm not sure why or what they are for though.

My path is /var/mediaext/tv shows

That is where all the stuff from play later records to as well as downloaded mkv files. They were showing up without issue, but just suddenly stopped.

My guess is this is related to the plugin load npe failure stuckless is looking in to that also causes issues with scheduledrecording events not firing. Perhaps depending on how many plugins you load the failure happens at different times causing different events to be missed.

Stuckless mentioned he had metadata lookups not run as well so these may be related to the same issue.

Or not... its just a guess.

k

[CollegeProject]

Originally Posted by jusjoken

Or not... its just a guess.

k

That's my thought or "guess" as well. I wouldn't go nuking your entire system just yet until this is further figured out. I would say the two are related. I am wondering if it's core related. If anyone can track it down will be Stuckless.

[panteragstk]

Originally Posted by CollegeProject

That's my thought or "guess" as well. I wouldn't go nuking your entire system just yet until this is further figured out. I would say the two are related. I am wondering if it's core related. If anyone can track it down will be Stuckless.

Yeah, I'm holding off doing anything until then.

[panteragstk]

I did a little more digging and it isn't that sage isn't picking up the video, it's that it isn't getting metadata. Even if I manually search it still isn't showing up in any of my views.

Very odd.

[stuckless]

So, I ended up having to stop using Phoenix 3 UI

I added SageTV event logging, and when Phoenix 3 is loaded, other than a "client connected" I never see any other events.

Gemstone, which also uses phoenix core/apis, does get the events.

I'm hoping to troubleshoot this more on the weekend, but for this week, I'm back into Gemstone.

There has to be something in the combination of Phoenix UI + Phoenix APIs that is causing sagetv to stop processing events.

[bialio]

Seems like it has to be something in how the Plugin is packaged - have you tried P2 to see if all that stuff still works? I'll look at the Plugin Manifests when I get home and see if anything jumps out at me...

[stuckless]

Originally Posted by bialio

Seems like it has to be something in how the Plugin is packaged - have you tried P2 to see if all that stuff still works? I'll look at the Plugin Manifests when I get home and see if anything jumps out at me...

I ran P2 for years and I never had an issue... I haven't tried P2 lately, but I know for sure I never had issues in the past.

My guesses so far is...

1. SageTV is eating the events and not passing them along because of the STV name (but again, P2 used a different STV name and it worked, and I looked at the sagetv code, I can't find anything in there to suggest that sagetv cares about the stv name)

2. I asked you to add the Refresh VFS and Refresh Menus... I'm wondering if that is causing some sort of hiccup in the ApplicationStarted Hook and somehow Phoenix core is doing something that is causing core to misbehave.

I've reviewed the event code in core, when P3 is loaded, I don't see core attempting to send events. In sagetv, if you set the property

debug_core_events=true

Then you will see a message like "Core is about to process ...." for every event that sagetv processes. When P3 is enabled, I see this for Client Connected, and then nothing.

I've looked at the <Hook> lines in the STV to see if Maybe there was something there... but ApplicationStarted is really the only thing that I can see that "might" cause something, but even then it's just reloading menus, vfs, etc.

[CollegeProject]

Originally Posted by stuckless

I've looked at the <Hook> lines in the STV to see if Maybe there was something there... but ApplicationStarted is really the only thing that I can see that "might" cause something, but even then it's just reloading menus, vfs, etc.

Just for reference I have refreshed VFS views in the STV and didn't see any issues.

[jusjoken]

Originally Posted by stuckless

1. SageTV is eating the events and not passing them along because of the STV name (but again, P2 used a different STV name and it worked, and I looked at the sagetv code, I can't find anything in there to suggest that sagetv cares about the stv name)

I think it is NOT this.... Gemstone 2 now uses an STVName="Gemstone" rather than Gemstone 1 which mimiced the STVName="SageTV7".

I just tested Gemstone 2 with the debug_core_events=true and Gemstone 2 is processing events to phoenix...

Core is about to process the event ImportingCompleted vars={FullReindex=false}
Core sending event ImportingCompleted to sagex.phoenix.plugin.PhoenixPlugin@d9a9bd vars={FullReindex=false}
DONE Core sending event ImportingCompleted to sagex.phoenix.plugin.PhoenixPlugin@d9a9bd
Seeker has finished the library import scan.

It's a shame you had to go back to Gemstone but I will dig and see if I can see other differences between Gemstone 2 and P3 to see if we can see why this is occuring.

k

[stuckless]

Originally Posted by jusjoken

It's a shame you had to go back to Gemstone but I will dig and see if I can see other differences between Gemstone 2 and P3 to see if we can see why this is occuring.
k

Gemstone is great too... but I was enjoying the "leaness" of Phoenix UI

[jusjoken]

I found the culprit.

In the ApplicationStarted hook, the call to....

phoenix_config_ReloadConfiguration()

...is breaking the event handling. If I remove that call then P3 properly handles the LibraryScan events and passes them to phoenix.

I have not looked any further into WHY that call is causing this but it is very repeatable and I am sure stuckless can dig into that call better than I.

Hope this helps get this resolved.

k

[stuckless]

Originally Posted by jusjoken

I found the culprit.

In the ApplicationStarted hook, the call to....

phoenix_config_ReloadConfiguration()

...is breaking the event handling. If I remove that call then P3 properly handles the LibraryScan events and passes them to phoenix.

I have not looked any further into WHY that call is causing this but it is very repeatable and I am sure stuckless can dig into that call better than I.

Hope this helps get this resolved.

k

So I found a deadlock issue in the SageTV core event manager that Phoenix is triggering when this API is called

I should have a fix in the sagetv core fairly soon.

[panteragstk]

Originally Posted by stuckless

So I found a deadlock issue in the SageTV core event manager that Phoenix is triggering when this API is called

I should have a fix in the sagetv core fairly soon.

Great news. Thanks for all the hard work guys.

[bialio]

Originally Posted by stuckless

So I found a deadlock issue in the SageTV core event manager that Phoenix is triggering when this API is called

I should have a fix in the sagetv core fairly soon.

Thanks for tracking it down stuck-joken. I was going to look for it this morning before heading into work - glad I checked the forums first!

I can remove that line from the STV if you need me to stuckless...

btl.