EPG NullPointerException

[graywolf]

Posting from thread in Software to here for the EPG folks are aware

Thu 8/2 20:23:36.140 [EPG@a386b8] Wizard writing out table info for SeriesInfo
Thu 8/2 20:23:36.478 [EPG@a386b8] Exception during Maintenance:java.lang.NullPointerException
Thu 8/2 20:23:36.478 [EPG@a386b8] java.lang.NullPointerException
Thu 8/2 20:23:36.479 [EPG@a386b8] 	at sage.SeriesInfo.write(SeriesInfo.java:201)
Thu 8/2 20:23:36.479 [EPG@a386b8] 	at sage.Wizard.saveDBFile(Wizard.java:7930)
Thu 8/2 20:23:36.479 [EPG@a386b8] 	at sage.Wizard.maintenance(Wizard.java:2369)
Thu 8/2 20:23:36.479 [EPG@a386b8] 	at sage.EPG.run(EPG.java:645)
Thu 8/2 20:23:36.479 [EPG@a386b8] 	at java.lang.Thread.run(Unknown Source)
Thu 8/2 20:23:36.479 [EPG@a386b8] sage.epg.sd.SDRipper@1f6b7c6 needs an update in 16:33:26
Thu 8/2 20:23:36.479 [EPG@a386b8] EPG needs an update in 993 minutes
Thu 8/2 20:23:36.479 [EPG@a386b8] EPG's works is done. Waiting...

Originally Posted by wnjj

The line that’s crashing is attempting to access an array of people associated with the series and one of them is null. Tracing back, the person object it can be null if the name has 0 length. I wonder if SD has some funky data and the EPG code isn’t filtering it?

[graywolf]

Question I have:
This has only happened on 1 of my SageTV setups.
It is not occurring on the other 2 SageTV setups.

Think the lineups should be the same, guess I need to double check.

Any way to determine WHICH series might be getting the null Person?

[wnjj]

Originally Posted by graywolf

Question I have:
This has only happened on 1 of my SageTV setups.
It is not occurring on the other 2 SageTV setups.

Think the lineups should be the same, guess I need to double check.

Any way to determine WHICH series might be getting the null Person?

That’s tough to tell without adding some debug code but it would seem to me it’d have to be one that isn’t already in the DB since the last startup. I haven’t built the JAR it awhile but some debug code and/or handling the NULL needs to be added to sort it out. I don’t know what kind of issue it will create if something else is referring to that missing person and it’s just skipped when saving. At a minimum, the “count” is already written so can’t be modified. I suppose we could create a “Mr. X” on the fly for the NULL entry so at least the DB can complete write out with debug code to display the series name.

[graywolf]

Another occurance where Wiz.bin just stops writing.

Anyone have suggestion or idea how to correct this?
Anything on my end to generate additional logs to help someone fix this?

Also, any thoughts why this is occurring on only 1 (always same one) of my Sage servers?

Thu 8/23 18:11:06.627 [EPG@11bd0e2] Wizard locating time holes in airing table...
Thu 8/23 18:11:11.865 [EPG@11bd0e2] Wizard plugging the 2304 time holes in the airing table...
Thu 8/23 18:11:14.334 [EPG@11bd0e2] Wizard fixing duration for 2377 noshow airings...
Thu 8/23 18:11:18.153 [EPG@11bd0e2] Wizard removing 0 expired Channels of 1061 total...
Thu 8/23 18:11:18.300 [EPG@11bd0e2] Wizard removing 3998 expired Shows of 117245 total...
Thu 8/23 18:11:22.796 [Ministry@1145bff] Ministry is waiting for 180 sec
Thu 8/23 18:11:27.363 [EPG@11bd0e2] Retaining 220145 total title & people & category & bonus ids.
Thu 8/23 18:11:27.373 [EPG@11bd0e2] Clearing out 549 titles of 41559 total.
Thu 8/23 18:11:28.491 [EPG@11bd0e2] Clearing out 0 prime titles of 0 total.
Thu 8/23 18:11:28.586 [EPG@11bd0e2] Clearing out 9474 people of 180155 total.
Thu 8/23 18:11:49.499 [EPG@11bd0e2] Clearing out 0 categories of 170 total.
Thu 8/23 18:11:49.549 [EPG@11bd0e2] Clearing out 0 subcategories of 277 total.
Thu 8/23 18:11:49.602 [EPG@11bd0e2] Clearing out 108 bonuses of 7538 total.
Thu 8/23 18:11:49.856 [EPG@11bd0e2] Wizard is fixing the media mask on the Show objects...
Thu 8/23 18:11:50.095 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdateShow): 239ms for 1 items in 1 loops, lock time 0 ms
Thu 8/23 18:11:50.145 [EPG@11bd0e2] Wizard is fixing the media mask on the Titles...
Thu 8/23 18:11:50.180 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdateTitle): 4ms for 176 items in 1 loops
Thu 8/23 18:11:50.231 [EPG@11bd0e2] Wizard is fixing the media mask on the Years...
Thu 8/23 18:11:50.246 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdateYears): 0ms for 0 items in 1 loops
Thu 8/23 18:11:50.296 [EPG@11bd0e2] Wizard is fixing the media mask on the Peoples...
Thu 8/23 18:11:50.576 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdatePeoples): 96ms for 19726 items in 1 loops
Thu 8/23 18:11:50.627 [EPG@11bd0e2] Wizard is fixing the media mask on the Categories...
Thu 8/23 18:11:50.650 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdateCategories): 0ms for 0 items in 1 loops
Thu 8/23 18:11:50.701 [EPG@11bd0e2] Wizard is fixing the media mask on the SubCategories...
Thu 8/23 18:11:50.736 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdateSubCategories): 0ms for 0 items in 1 loops
Thu 8/23 18:11:50.786 [EPG@11bd0e2] Wizard is fixing the media mask on the Rated...
Thu 8/23 18:11:50.798 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdateRated): 0ms for 0 items in 1 loops
Thu 8/23 18:11:50.848 [EPG@11bd0e2] Wizard is fixing the media mask on the PR...
Thu 8/23 18:11:50.861 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdatePRs): 0ms for 0 items in 1 loops
Thu 8/23 18:11:50.912 [EPG@11bd0e2] Wizard is fixing the media mask on the ERs...
Thu 8/23 18:11:50.929 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdateERs): 0ms for 0 items in 1 loops
Thu 8/23 18:11:50.979 [EPG@11bd0e2] Wizard is fixing the media mask on the Bonus...
Thu 8/23 18:11:51.011 [EPG@11bd0e2] MaintenceMetric(MediaMaskUpdateBonus): 1ms for 0 items in 1 loops
Thu 8/23 18:11:51.115 [EPG@11bd0e2] Wizard backing up database file...
Thu 8/23 18:11:51.115 [LucenePersonTransactionTask@760d7] Snapshot index person snap-count: 10
Thu 8/23 18:11:51.115 [LuceneShowTransactionTask@919dca] Snapshot index show snap-count: 10
Thu 8/23 18:11:51.117 [EPG@11bd0e2] Wizard compressing new file with version 87...
Thu 8/23 18:11:51.120 [EPG@11bd0e2] Wizard writing out table info for Year
Thu 8/23 18:11:51.120 [EPG@11bd0e2] Wizard writing out table info for Network
Thu 8/23 18:11:51.120 [EPG@11bd0e2] Wizard writing out table info for Title
Thu 8/23 18:11:51.154 [EPG@11bd0e2] Wizard writing out table info for Channel
Thu 8/23 18:11:51.157 [EPG@11bd0e2] Wizard writing out table info for Bonus
Thu 8/23 18:11:51.160 [EPG@11bd0e2] Wizard writing out table info for People
Thu 8/23 18:11:51.396 [EPG@11bd0e2] Wizard writing out table info for SubCategory
Thu 8/23 18:11:51.396 [EPG@11bd0e2] Wizard writing out table info for Rated
Thu 8/23 18:11:51.396 [EPG@11bd0e2] Wizard writing out table info for ParentalRating
Thu 8/23 18:11:51.396 [EPG@11bd0e2] Wizard writing out table info for ExtendedRating
Thu 8/23 18:11:51.397 [EPG@11bd0e2] Wizard writing out table info for Category
Thu 8/23 18:11:51.397 [EPG@11bd0e2] Wizard writing out table info for PrimeTitle
Thu 8/23 18:11:51.397 [EPG@11bd0e2] Wizard writing out table info for Show
Thu 8/23 18:11:52.369 [EPG@11bd0e2] Wizard writing out table info for Airing
Thu 8/23 18:11:52.819 [EPG@11bd0e2] Wizard writing out table info for ManualRecord
Thu 8/23 18:11:52.828 [EPG@11bd0e2] Wizard writing out table info for MediaFile
Thu 8/23 18:11:53.638 [EPG@11bd0e2] Wizard writing out table info for Watched
Thu 8/23 18:11:53.650 [EPG@11bd0e2] Wizard writing out table info for Agent
Thu 8/23 18:11:53.659 [EPG@11bd0e2] Wizard writing out table info for Wasted
Thu 8/23 18:11:53.662 [EPG@11bd0e2] Wizard writing out table info for Playlist
Thu 8/23 18:11:53.662 [EPG@11bd0e2] Wizard writing out table info for TVEditorial
Thu 8/23 18:11:53.662 [EPG@11bd0e2] Wizard writing out table info for SeriesInfo
Thu 8/23 18:11:53.906 [EPG@11bd0e2] Exception during Maintenance:java.lang.NullPointerException
Thu 8/23 18:11:53.907 [EPG@11bd0e2] java.lang.NullPointerException
Thu 8/23 18:11:53.907 [EPG@11bd0e2] 	at sage.SeriesInfo.write(SeriesInfo.java:201)
Thu 8/23 18:11:53.907 [EPG@11bd0e2] 	at sage.Wizard.saveDBFile(Wizard.java:7930)
Thu 8/23 18:11:53.907 [EPG@11bd0e2] 	at sage.Wizard.maintenance(Wizard.java:2369)
Thu 8/23 18:11:53.907 [EPG@11bd0e2] 	at sage.EPG.run(EPG.java:645)
Thu 8/23 18:11:53.907 [EPG@11bd0e2] 	at java.lang.Thread.run(Unknown Source)
Thu 8/23 18:11:53.907 [EPG@11bd0e2] sage.epg.sd.SDRipper@df4c8 needs an update in 15:49:35
Thu 8/23 18:11:53.907 [EPG@11bd0e2] EPG needs an update in 949 minutes
Thu 8/23 18:11:53.907 [EPG@11bd0e2] EPG's works is done. Waiting...

[graywolf]

So I'm a very basic coder when it comes to Java (just enough to be dangerous)

So it looks like sagetv/java/sage/SeriesInfo.java https://github.com/google/sagetv/blo...eriesInfo.java it is out.writeInt(useLookupIdx ? people[i].lookupIdx : people[i].id); causing the error?

Issue #383 opened on GitHub

void write(DataOutput out, int flags) throws IOException
  {
    super.write(out, flags);
    boolean useLookupIdx = (flags & Wizard.WRITE_OPT_USE_ARRAY_INDICES) != 0;
    out.writeInt(legacySeriesID);
    out.writeInt((title == null) ? 0 : (useLookupIdx ? title.lookupIdx : title.id));
    out.writeInt((network == null) ? 0 : (useLookupIdx ? network.lookupIdx : network.id));
    out.writeUTF(description);
    out.writeUTF(history);
    out.writeUTF(premiereDate);
    out.writeUTF(finaleDate);
    out.writeUTF(airDow);
    out.writeUTF(airHrMin);
    out.writeInt(people.length);
    for (int i = 0; i < people.length; i++)
    {
      out.writeInt(useLookupIdx ? people[i].lookupIdx : people[i].id);
      out.writeUTF(characters[i]);
    }
    out.writeUTF(imageUrl);

[wnjj]

Originally Posted by graywolf

So I'm a very basic coder when it comes to Java (just enough to be dangerous)

So it looks like sagetv/java/sage/SeriesInfo.java https://github.com/google/sagetv/blo...eriesInfo.java it is out.writeInt(useLookupIdx ? people[i].lookupIdx : people[i].id); causing the error?

Issue #383 opened on GitHub

void write(DataOutput out, int flags) throws IOException
  {
    super.write(out, flags);
    boolean useLookupIdx = (flags & Wizard.WRITE_OPT_USE_ARRAY_INDICES) != 0;
    out.writeInt(legacySeriesID);
    out.writeInt((title == null) ? 0 : (useLookupIdx ? title.lookupIdx : title.id));
    out.writeInt((network == null) ? 0 : (useLookupIdx ? network.lookupIdx : network.id));
    out.writeUTF(description);
    out.writeUTF(history);
    out.writeUTF(premiereDate);
    out.writeUTF(finaleDate);
    out.writeUTF(airDow);
    out.writeUTF(airHrMin);
    out.writeInt(people.length);
    for (int i = 0; i < people.length; i++)
    {
      out.writeInt(useLookupIdx ? people[i].lookupIdx : people[i].id);
      out.writeUTF(characters[i]);
    }
    out.writeUTF(imageUrl);

Yes. 'people' is an array of 'person' and if any elements are NULL, using .lookupIdx or .id on a NULL causes that error. Upstream where this array gets built from EPG, I saw code where a person can be NULL if their name is blank. That's really where it needs fixed I think. If the person is blank, the entire relationship should not exist. If we just want to skip the bad person, what would we write into the DB? The problem is the length is already written just above the loop.

A hack would be to first loop through all of the people and count how many are NULL before writing out length and instead write out the correct length before the loop. If I find some time I could try to build you a JAR to try out.

[wnjj]

If you want to give it a shot, I added the following code to the 9.1.9 jar and built a new one:

    out.writeUTF(airHrMin);
    // check/discard NULL people
    int num_people = 0;
    for (int i = 0; i < people.length; i++)
      if (people[i] != null) num_people++;
    out.writeInt(num_people); // actual number
//    out.writeInt(people.length);
    for (int i = 0; i < people.length; i++)
    {
      if (people[i] != null)
      {
        out.writeInt(useLookupIdx ? people[i].lookupIdx : people[i].id);
        out.writeUTF(characters[i]);
      }
    }
    out.writeUTF(imageUrl);

I've never shared via Dropbox before but I think this link should let you download it:

https://www.dropbox.com/s/ll6yieu0ak...erson_fix?dl=0

Rename back to Sage.jar. Backup your old one first!

[graywolf]

@wnjj - that would be wonderful. Also, if not too much trouble, maybe spit out to sagetv_0.txt the Series and maybe other debug info?

If we just want to skip the bad person, what would we write into the DB?

Maybe just an X

Will gladly give the JAR a try.

[wnjj]

Originally Posted by graywolf

@wnjj - that would be wonderful. Also, if not too much trouble, maybe spit out to sagetv_0.txt the Series and maybe other debug info?


Maybe just an X

Will gladly give the JAR a try.

More importantly: Back up your wiz.bin!

Oh yeah. I forgot I was going to do that. Duh! Stand by for an update...

[wnjj]

New code:

    out.writeUTF(airHrMin);
    // check/discard NULL people
    int num_people = 0;
    for (int i = 0; i < people.length; i++)
    {
      if (people[i] == null)
      {
        if (Sage.DBG) System.out.println("Null person in SeriesInfo! Series=" + getTitle() + ", person #" + i);
      }
      else
      {
        num_people++;
      }
    }
    out.writeInt(num_people); // actual number
//    out.writeInt(people.length);
    for (int i = 0; i < people.length; i++)
    {
      if (people[i] != null)
      {
        out.writeInt(useLookupIdx ? people[i].lookupIdx : people[i].id);
        out.writeUTF(characters[i]);
      }
    }
    out.writeUTF(imageUrl);

Same link:

https://www.dropbox.com/s/ll6yieu0ak...erson_fix?dl=0

[wnjj]

A couple more comments:

1. Checking again inside SD ripper, there are NULL checks and I can't see how any NULL person is getting added to the seriesinfo, yet there is your error.
2. The better fix would be to block it in Wizard.java::addSeriesInfo() so no NULL person is even put there in the first place. Preventing it from writing to wiz.db will work for that, but other things that refer to these people may not like the null in there.

[JREkiwi]

Originally Posted by wnjj

Checking again inside SD ripper, there are NULL checks and I can't see how any NULL person is getting added to the seriesinfo, yet there is your error.

I've been having the same problem and am not using SD EPG. I suspect it's more likely caused by something else that's modifying show metadata like IMDB or BMT.

John

[wnjj]

Originally Posted by JREkiwi

I've been having the same problem and am not using SD EPG. I suspect it's more likely caused by something else that's modifying show metadata like IMDB or BMT.

John

Thanks for that info. I see there is an API, "AddSeriesInfo" that allows plugins to modify that data. The right answer is to fix Wizard to not install those NULL people into the DB. I'll fix it there.

[graywolf]

@wnjj - Thanks. Was able to download it.
Will replace in the morning.

Doing the following in the morning:
1. Stop SageTV
2. Backup SageTV\SageTV\Sage.jar & SageTV\SageTV\wiz.bin
3. Copy Sage.jar_9.1.9_seriesinfo_nullperson_fix to SageTV\SageTV\Sage.jar
4. Restart SageTV

Monitor sagetv_#.txt files for Null person in SeriesInfo! Series=

[wnjj]

Originally Posted by graywolf

@wnjj - Thanks. Was able to download it.
Will replace in the morning.

Doing the following in the morning:
1. Stop SageTV
2. Backup SageTV\SageTV\Sage.jar & SageTV\SageTV\wiz.bin
3. Copy Sage.jar_9.1.9_seriesinfo_nullperson_fix to SageTV\SageTV\Sage.jar
4. Restart SageTV

Monitor sagetv_#.txt files for Null person in SeriesInfo! Series=

Based upon JREkiwi's comments, I moved the fix into Wizard.java instead which is more proper. That way plugins cannot add nulls either. I've updated the file at the same link and changed the log message slightly:

        for (int i = 0, j = 0; i < people.length; i++)
        {
          if (people[i] == null)
          {
            if (Sage.DBG) System.out.println("addSeriesInfo: Attempting to add null person!  Series=" + series.getTitle() + ", person #" + i);
          }
          else
          {
            series.people[j] = people[i];
            series.characters[j] = new String(characters[i]);
            j++;
          }
        }

This is far less hacky and only adds valid people.

[graywolf]

Originally Posted by JREkiwi

I've been having the same problem and am not using SD EPG. I suspect it's more likely caused by something else that's modifying show metadata like IMDB or BMT.

John

Don't use IMDB but do have/use BMT

[JREkiwi]

Originally Posted by graywolf

Don't use IMDB but do have/use BMT

That narrows it down then, it also means I don't need to look through the IMDB code

John

[wnjj]

Hey graywolf,

I just realized there's a bug in my "simple" fix.

I updated the version on Dropbox for you to grab. The logging in the broken one will work and show when one is added, but will still result in a NULL ending up in the people list. This version also has the API tweaks I'm doing for davidb but they shouldn't affect your testing at all.

[graywolf]

Thanks. Was out of town for a couple days.
Will apply the latest fix today.
Fortunately so far no repeat of the issue

[graywolf]

So far, so good.
Have not had another occurrence of this issue.
Have been checking the sagetv_#.txt logs also for "null person" and no hits either.

Will keep checking since this was so sporadic.