SOS wife is going to kill me - Upgraded to Windows 7, Sage doesn't start

[michelkenny]

I've been running SageTV 7.0.16 on Windows Server 2003. Decided to upgrade to Windows 7. At the same time I replaced my PVR-500 with an HVR-2250. I also have two HDPVRs. I backed up my entire SageTV folder, installed Windows 7, installed SageTV 7.0.16, copied back my SageTV folder. Now when I try to start the service, it starts and stops. If I try to load the front end, I get the following error:

An exception occured in Java: java.lang.NullPointerException


Now I am trying to load the front end via a Remote Desktop connection so that might be the problem for the front end, but the service should start. I have also disabled all of my capture devices in Device Manager but not success.

The SageTV log file:

Thu 9/16 23:25:30.989 [main@16a55fa] user.dir2=C:\Program Files\SageTV\SageTV
Thu 9/16 23:25:30.990 [main@16a55fa] classpath=C:\Program Files\SageTV\SageTV\Sage.jar;C:\Program Files\SageTV\SageTV\xerces.jar;C:\Program Files\SageTV\SageTV\plugin.jar;C:\Program Files\SageTV\SageTV\;;JARs\ant-1.6.5.jar;JARs\commons-codec-1.3.jar;JARs\commons-exec-1.0.1.jar;JARs\commons-io-1.4.jar;JARs\commons-jxpath-1.1.jar;JARs\commons-lang-2.4.jar;JARs\commons-logging-1.1.1.jar;JARs\commons-logging-api-1.1.1.jar;JARs\core-3.1.1.jar;JARs\df_sleep_timer.jar;JARs\gkusnick.sagetv.jar;JARs\gwt-servlet.jar;JARs\gxt.jar;JARs\jcifs-1.1.6.jar;JARs\jdic.jar;JARs\jetty-6.1.19.jar;JARs\jetty-ajp-6.1.19.jar;JARs\jetty-rewrite-handler-6.1.19.jar;JARs\jetty-sslengine-6.1.19.jar;JARs\jetty-starter.jar;JARs\jetty-util-6.1.19.jar;JARs\json.jar;JARs\jsp-2.1-jetty-6.1.19.jar;JARs\jsp-2.1.jar;JARs\jsp-api-2.1.jar;JARs\libgrowl.jar;JARs\log4j-1.2.15.jar;JARs\mail.jar;JARs\nielm_sageutls.jar;JARs\nielm_sagexmlinfo.jar;JARs\sagealert-common.jar;JARs\sagealert.jar;JARs\sagex-api.jar;JARs\sbbi-upnplib-1.0.3.jar;JARs\servlet-api-2.5-6.1.19.jar;JARs\servlet.jar;JARs\sqlitejdbc-v056.jar;JARs\twitter4j-core-2.1.2.jar;JARs\vecmath.jar
Thu 9/16 23:25:30.991 [main@16a55fa] JVM version=1.6.0_21
Thu 9/16 23:25:30.991 [main@16a55fa] OS=Windows 7 6.1
Thu 9/16 23:25:30.992 [main@16a55fa] locale=en_CA
Thu 9/16 23:25:31.133 [main@16a55fa] Succesfully setup system shell hook
Thu 9/16 23:25:31.133 [main@16a55fa] not specifiy WinkeyboardHook in registery, load default one
Thu 9/16 23:25:31.262 [main@16a55fa] ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/splash.gif
Thu 9/16 23:25:31.271 [main@16a55fa] ImageUtils creating BI copy sun.awt.image.ToolkitImage@affc70 w=520 h=350 freeMem=20331264 totalMem=24379392
Thu 9/16 23:25:31.287 [main@16a55fa] SageTV V7.0.16.238
Thu 9/16 23:25:31.290 [main@16a55fa] hostname=Sage
Thu 9/16 23:25:31.294 [main@16a55fa] Splash: User Interface Manager is initializing...
Thu 9/16 23:25:31.339 [main@16a55fa] ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon.gif
Thu 9/16 23:25:31.340 [main@16a55fa] ImageUtils creating BI copy sun.awt.image.ToolkitImage@c2ea3f w=32 h=32 freeMem=17944400 totalMem=24379392
Thu 9/16 23:25:31.422 [main@16a55fa] Splash: Rendering Engine is initializing...
Thu 9/16 23:25:31.423 [main@16a55fa] Splash: Object Database is initializing...
Thu 9/16 23:25:31.487 [main@16a55fa] dbFile=C:\Program Files\SageTV\SageTV\Wiz.bin dbBackupFile=C:\Program Files\SageTV\SageTV\Wiz.bak
Thu 9/16 23:25:31.487 [main@16a55fa] Wizard starting to load database info...
Thu 9/16 23:25:31.488 [main@16a55fa] Splash: Object Database Source is initializing...
Thu 9/16 23:25:31.490 [main@16a55fa] DBFile at version 70 FileSize=16026941
Thu 9/16 23:25:31.490 [main@16a55fa] Wizard allocating table for Year of size 97
Thu 9/16 23:25:31.492 [main@16a55fa] Splash: Object Database is initializing... 0% done
Thu 9/16 23:25:31.492 [main@16a55fa] Wizard loading main index for Year bytes=1073
Thu 9/16 23:25:31.493 [main@16a55fa] Splash: Object Database is initializing... 0% done
Thu 9/16 23:25:31.493 [main@16a55fa] Wizard allocating table for Network of size 276
Thu 9/16 23:25:31.494 [main@16a55fa] Splash: Object Database is initializing... 0% done
Thu 9/16 23:25:31.494 [main@16a55fa] Wizard loading main index for Network bytes=3620
Thu 9/16 23:25:31.496 [main@16a55fa] Splash: Object Database is initializing... 0% done
Thu 9/16 23:25:31.496 [main@16a55fa] Wizard allocating table for Title of size 15785
Thu 9/16 23:25:31.496 [main@16a55fa] Splash: Object Database is initializing... 0% done
Thu 9/16 23:25:31.496 [main@16a55fa] Wizard loading main index for Title bytes=630860
Thu 9/16 23:25:31.517 [main@16a55fa] Wizard building alt. index 0 for Title
Thu 9/16 23:25:31.526 [main@16a55fa] Splash: Object Database is initializing... 0% done
Thu 9/16 23:25:31.527 [main@16a55fa] Wizard allocating table for Channel of size 484
Thu 9/16 23:25:31.528 [main@16a55fa] Splash: Object Database is initializing... 4% done
Thu 9/16 23:25:31.528 [main@16a55fa] Wizard loading main index for Channel bytes=25269
Thu 9/16 23:25:31.530 [main@16a55fa] Splash: Object Database is initializing... 4% done
Thu 9/16 23:25:31.531 [main@16a55fa] Wizard allocating table for People of size 24961
Thu 9/16 23:25:31.531 [main@16a55fa] Splash: Object Database is initializing... 4% done
Thu 9/16 23:25:31.531 [main@16a55fa] Wizard loading main index for People bytes=503734
Thu 9/16 23:25:31.547 [main@16a55fa] Wizard building alt. index 0 for People
Thu 9/16 23:25:31.562 [main@16a55fa] Splash: Object Database is initializing... 4% done
Thu 9/16 23:25:31.562 [main@16a55fa] Wizard allocating table for SubCategory of size 128
Thu 9/16 23:25:31.563 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.563 [main@16a55fa] Wizard loading main index for SubCategory bytes=1998
Thu 9/16 23:25:31.563 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.564 [main@16a55fa] Wizard allocating table for Rated of size 7
Thu 9/16 23:25:31.564 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.564 [main@16a55fa] Wizard loading main index for Rated bytes=73
Thu 9/16 23:25:31.564 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.564 [main@16a55fa] Wizard allocating table for ParentalRating of size 0
Thu 9/16 23:25:31.565 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.565 [main@16a55fa] Wizard allocating table for ExtendedRating of size 10
Thu 9/16 23:25:31.565 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.565 [main@16a55fa] Wizard loading main index for ExtendedRating bytes=196
Thu 9/16 23:25:31.566 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.566 [main@16a55fa] Wizard allocating table for Category of size 95
Thu 9/16 23:25:31.566 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.566 [main@16a55fa] Wizard loading main index for Category bytes=1501
Thu 9/16 23:25:31.567 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.567 [main@16a55fa] Wizard allocating table for PrimeTitle of size 0
Thu 9/16 23:25:31.567 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.567 [main@16a55fa] Wizard allocating table for Bonus of size 193
Thu 9/16 23:25:31.567 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.568 [main@16a55fa] Wizard loading main index for Bonus bytes=4770
Thu 9/16 23:25:31.568 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.568 [main@16a55fa] Wizard allocating table for Show of size 26926
Thu 9/16 23:25:31.569 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.569 [main@16a55fa] Wizard loading main index for Show bytes=5955816
Thu 9/16 23:25:31.804 [main@16a55fa] Wizard building alt. index 0 for Show
Thu 9/16 23:25:31.822 [main@16a55fa] Splash: Object Database is initializing... 7% done
Thu 9/16 23:25:31.822 [main@16a55fa] Wizard allocating table for Airing of size 75936
Thu 9/16 23:25:31.823 [main@16a55fa] Splash: Object Database is initializing... 44% done
Thu 9/16 23:25:31.823 [main@16a55fa] Wizard loading main index for Airing bytes=2505894
Thu 9/16 23:25:31.868 [main@16a55fa] Wizard building alt. index 0 for Airing
Thu 9/16 23:25:31.894 [main@16a55fa] Wizard building alt. index 1 for Airing
Thu 9/16 23:25:31.919 [main@16a55fa] Splash: Object Database is initializing... 44% done
Thu 9/16 23:25:31.920 [main@16a55fa] Wizard allocating table for ManualRecord of size 11
Thu 9/16 23:25:31.920 [main@16a55fa] Splash: Object Database is initializing... 60% done
Thu 9/16 23:25:31.920 [main@16a55fa] Wizard loading main index for ManualRecord bytes=611
Thu 9/16 23:25:31.923 [main@16a55fa] Splash: Object Database is initializing... 60% done
Thu 9/16 23:25:31.923 [main@16a55fa] Wizard allocating table for MediaFile of size 7886
Thu 9/16 23:25:31.923 [main@16a55fa] Splash: Object Database is initializing... 60% done
Thu 9/16 23:25:31.924 [main@16a55fa] Wizard loading main index for MediaFile bytes=3466308
Thu 9/16 23:25:32.224 [main@16a55fa] Wizard building alt. index 0 for MediaFile
Thu 9/16 23:25:32.226 [main@16a55fa] Wizard building alt. index 1 for MediaFile
Thu 9/16 23:25:32.256 [main@16a55fa] Splash: Object Database is initializing... 60% done
Thu 9/16 23:25:32.256 [main@16a55fa] Wizard allocating table for Watched of size 5975
Thu 9/16 23:25:32.257 [main@16a55fa] Splash: Object Database is initializing... 82% done
Thu 9/16 23:25:32.257 [main@16a55fa] Wizard loading main index for Watched bytes=340581
Thu 9/16 23:25:32.263 [main@16a55fa] Wizard building alt. index 0 for Watched
Thu 9/16 23:25:32.266 [main@16a55fa] Splash: Object Database is initializing... 82% done
Thu 9/16 23:25:32.266 [main@16a55fa] Wizard allocating table for Agent of size 722
Thu 9/16 23:25:32.266 [main@16a55fa] Splash: Object Database is initializing... 84% done
Thu 9/16 23:25:32.266 [main@16a55fa] Wizard loading main index for Agent bytes=74472
Thu 9/16 23:25:32.273 [main@16a55fa] Wizard building alt. index 0 for Agent
Thu 9/16 23:25:32.275 [main@16a55fa] Splash: Object Database is initializing... 84% done
Thu 9/16 23:25:32.275 [main@16a55fa] Wizard allocating table for Wasted of size 4822
Thu 9/16 23:25:32.276 [main@16a55fa] Splash: Object Database is initializing... 84% done
Thu 9/16 23:25:32.276 [main@16a55fa] Wizard loading main index for Wasted bytes=48226
Thu 9/16 23:25:32.277 [main@16a55fa] Splash: Object Database is initializing... 84% done
Thu 9/16 23:25:32.278 [main@16a55fa] Wizard allocating table for Playlist of size 1
Thu 9/16 23:25:32.278 [main@16a55fa] Splash: Object Database is initializing... 85% done
Thu 9/16 23:25:32.278 [main@16a55fa] Wizard loading main index for Playlist bytes=33
Thu 9/16 23:25:32.282 [main@16a55fa] Splash: Object Database is initializing... 85% done
Thu 9/16 23:25:32.282 [main@16a55fa] Wizard allocating table for TVEditorial of size 223
Thu 9/16 23:25:32.283 [main@16a55fa] Splash: Object Database is initializing... 85% done
Thu 9/16 23:25:32.283 [main@16a55fa] Wizard loading main index for TVEditorial bytes=95730
Thu 9/16 23:25:32.286 [main@16a55fa] Splash: Object Database is initializing... 85% done
Thu 9/16 23:25:32.286 [main@16a55fa] Wizard allocating table for SeriesInfo of size 4768
Thu 9/16 23:25:32.286 [main@16a55fa] Splash: Object Database is initializing... 85% done
Thu 9/16 23:25:32.287 [main@16a55fa] Wizard loading main index for SeriesInfo bytes=2349265
Thu 9/16 23:25:32.339 [main@16a55fa] Splash: Object Database is initializing... 85% done
Thu 9/16 23:25:32.340 [main@16a55fa] Wizard processing transactional records...
Thu 9/16 23:25:32.340 [main@16a55fa] Splash: Object Database is initializing... 100% done
Thu 9/16 23:25:32.343 [main@16a55fa] Wizard performing validation on database objects...
Thu 9/16 23:25:32.384 [main@16a55fa] Wizard DONE loading database info. loadTime=0.897 sec
Thu 9/16 23:25:32.384 [main@16a55fa] Splash: Object Database is initializing... 100% done
Thu 9/16 23:25:32.386 [main@16a55fa] Splash: EPG is initializing...
Thu 9/16 23:25:32.393 [main@16a55fa] Increased hash set pool to size=1
Thu 9/16 23:25:32.413 [main@16a55fa] Splash: Profiler is initializing...
Thu 9/16 23:25:32.415 [main@16a55fa] Loaded 0 messages from system message log file
Thu 9/16 23:25:32.528 [main@16a55fa] Splash: Acquisition System is initializing...
Thu 9/16 23:25:32.534 [main@16a55fa] MMC calling detectCaptureDevices on sage.ch@1ef8cf3
Thu 9/16 23:25:32.535 [main@16a55fa] devices detected=[]
Thu 9/16 23:25:32.535 [main@16a55fa] EncoderMap={}
Thu 9/16 23:25:32.536 [main@16a55fa] MMC calling detectCaptureDevices on sage.l@ecd7e
Thu 9/16 23:25:32.536 [main@16a55fa] Splash: DirectShow WDM Capture Manager is initializing...
Thu 9/16 23:25:32.539 [main@16a55fa] Setup globalInvalidParameterHandler
Thu 9/16 23:25:32.539 [main@16a55fa] Device detecting->:{65E8773D-8F56-11D0-A3B9-00A0C9223196}
Thu 9/16 23:25:32.543 [main@16a55fa] Device detecting->:{FD0A5AF4-B41D-11d2-9C95-00C04F7971E0}
Thu 9/16 23:25:32.543 [main@16a55fa] Device detecting->:{71985F48-1CA1-11d3-9CC8-00C04F7971E0}
Thu 9/16 23:25:32.544 [main@16a55fa] systemCapDevices=[]
Thu 9/16 23:25:32.545 [main@16a55fa] Checking encoder key:-431556906
Thu 9/16 23:25:32.548 [main@16a55fa] Created DShowCapDev object for:Hauppauge HD PVR Capture Device
Thu 9/16 23:25:32.549 [main@16a55fa] Checking encoder key:1642691032
Thu 9/16 23:25:32.550 [main@16a55fa] Created DShowCapDev object for:Hauppauge WinTV PVR PCI II Capture
Thu 9/16 23:25:32.550 [main@16a55fa] Checking encoder key:-1674637831
Thu 9/16 23:25:32.551 [main@16a55fa] Created DShowCapDev object for:Hauppauge HD PVR Capture Device #2
Thu 9/16 23:25:32.551 [main@16a55fa] Checking encoder key:551195575
Thu 9/16 23:25:32.552 [main@16a55fa] Created DShowCapDev object for:Hauppauge WinTV PVR PCI II Capture #2
Thu 9/16 23:25:32.552 [main@16a55fa] EncoderMap1={Hauppauge HD PVR Capture Device=Hauppauge HD PVR Capture Device, Hauppauge WinTV PVR PCI II Capture=Hauppauge WinTV PVR PCI II Capture, Hauppauge HD PVR Capture Device #2=Hauppauge HD PVR Capture Device #2, Hauppauge WinTV PVR PCI II Capture #2=Hauppauge WinTV PVR PCI II Capture #2}
Thu 9/16 23:25:32.554 [main@16a55fa] Capture device Hauppauge HD PVR Capture Device (0) does not exist 
Thu 9/16 23:25:32.554 [main@16a55fa] Encoder failed the check:Hauppauge HD PVR Capture Device
Thu 9/16 23:25:32.554 [main@16a55fa] Saving properties file to C:\Program Files\SageTV\SageTV\Sage.properties
Thu 9/16 23:25:32.767 [main@16a55fa] Removing encoder because it failed the check:Hauppauge HD PVR Capture Device
Thu 9/16 23:25:32.769 [main@16a55fa] Capture device Hauppauge WinTV PVR PCI II Capture (0) does not exist 
Thu 9/16 23:25:32.770 [main@16a55fa] Encoder failed the check:Hauppauge WinTV PVR PCI II Capture
Thu 9/16 23:25:32.770 [main@16a55fa] Saving properties file to C:\Program Files\SageTV\SageTV\Sage.properties
Thu 9/16 23:25:32.880 [main@16a55fa] Removing encoder because it failed the check:Hauppauge WinTV PVR PCI II Capture
Thu 9/16 23:25:32.882 [main@16a55fa] Capture device Hauppauge HD PVR Capture Device (1) does not exist 
Thu 9/16 23:25:32.882 [main@16a55fa] Encoder failed the check:Hauppauge HD PVR Capture Device #2
Thu 9/16 23:25:32.882 [main@16a55fa] Saving properties file to C:\Program Files\SageTV\SageTV\Sage.properties
Thu 9/16 23:25:32.963 [main@16a55fa] Removing encoder because it failed the check:Hauppauge HD PVR Capture Device #2
Thu 9/16 23:25:32.965 [main@16a55fa] Capture device Hauppauge WinTV PVR PCI II Capture (1) does not exist 
Thu 9/16 23:25:32.965 [main@16a55fa] Encoder failed the check:Hauppauge WinTV PVR PCI II Capture #2
Thu 9/16 23:25:32.965 [main@16a55fa] Saving properties file to C:\Program Files\SageTV\SageTV\Sage.properties
Thu 9/16 23:25:33.045 [main@16a55fa] Removing encoder because it failed the check:Hauppauge WinTV PVR PCI II Capture #2
Thu 9/16 23:25:33.045 [main@16a55fa] devices detected=[]
Thu 9/16 23:25:33.046 [main@16a55fa] EncoderMap={}
Thu 9/16 23:25:33.046 [main@16a55fa] Splash: SageTV Core is initializing...
Thu 9/16 23:25:33.074 [main@16a55fa] Checking video directories for new files
Thu 9/16 23:25:33.075 [main@16a55fa] Seeker removing LiveStreamMF because the source is gone: MediaFile[id=1352689 FA[BAD AIRING] mask=V host=Sage encodedBy=Hauppauge WinTV PVR PCI II Capture TV Tuner format=MPEG2-PS 0:00:00 0 kbps [#0 Video[MPEG2-Video 29.97 fps 720x480 4:3 12000 kbps interlaced]#1 Audio[MP2 48000 Hz 2 channels 384 kbps]]]

Any help would be greatly appreciated, since my wife will kill me if she can't watch anything for the whole day tomorrow until I come back from work.

[michelkenny]

Well it looks like it doesn't like my old Wiz.bin. I did a fresh installed, copied only my Wiz.bin and the problem happens. I remove my Wiz.bin and all is well...

[Smiley]

I had the same problem on a fresh install of both Windows 7 and the latest beta of SageTV - for me the problem was that it was running in server mode using 'Local System' for credentials which apparently did not have sufficient access rights. When I changed the user to my local user everything started up as expected.

[ranger]

You may also want to look at this thread. http://forums.sagetv.com/forums/showthread.php?t=50618

[michelkenny]

Originally Posted by ranger

You may also want to look at this thread. http://forums.sagetv.com/forums/showthread.php?t=50618

Hallelujah that worked!!!!