SageTV Community  

Go Back   SageTV Community > SageTV Development and Customizations > SageTV v7 Customizations
Forum Rules FAQs Community Downloads Today's Posts Search

Notices

SageTV v7 Customizations This forums is for discussing and sharing user-created modifications for the SageTV version 7 application created by using the SageTV Studio or through the use of external plugins. Use this forum to discuss plugins for SageTV version 7 and newer.

Reply
 
Thread Tools Search this Thread Display Modes
  #1  
Old 12-18-2010, 11:50 PM
coppit coppit is offline
Sage Advanced User
 
Join Date: Mar 2003
Posts: 176
Need help with SJQv4 remote agent

Hi all,

My HTPC is a pretty weak Atom processor, so I'm trying to set up a remote agent on my desktop PC to run Mediashrink.

I have the agent started as a service, and I've registered it with the server. I've mounted the data drive on my HTPC as the G: drive on my desktop PC. My saved recordings are in G:\SageTV, and I've installed Mediashrink in G:\Mediashrink.

I can run Mediashrink on the command line okay. But every task I set up with SageTV fails without any logs. Here's my task config:

Executable: G:\Mediashrink\Mediashrink.exe
Executable arguments: "G\SageTV\$SJQ4_LAST_SEGMENT" /inPlace /batch /vprofile /onePass HQ /vbitrate 2500
Test Script:
Test Script Arguments:
Maximum Instances: 1
Maximum Return Code: 0
Minimum Return Code: 0\
Maximum Time: 86400
Resources: 100
Schedule: ON
Maximum Time Ratio: 1.0

What am I doing wrong? Can I use UNC paths like \\htpc\datadrive\SageTV instead of G:\SageTV?
Reply With Quote
  #2  
Old 12-19-2010, 08:51 AM
coppit coppit is offline
Sage Advanced User
 
Join Date: Mar 2003
Posts: 176
Some progress

I found the logs.

Code:
STATUS | wrapper  | 2010/12/19 00:11:17 | --> Wrapper Started as Service
STATUS | wrapper  | 2010/12/19 00:11:17 | Java Service Wrapper Community Edition 32-bit 3.5.6
STATUS | wrapper  | 2010/12/19 00:11:17 |   Copyright (C) 1999-2010 Tanuki Software, Ltd. All Rights Reserved.
STATUS | wrapper  | 2010/12/19 00:11:17 |     http://wrapper.tanukisoftware.com
STATUS | wrapper  | 2010/12/19 00:11:17 | 
STATUS | wrapper  | 2010/12/19 00:11:17 | Launching a JVM...
INFO   | jvm 1    | 2010/12/19 00:11:17 | WrapperManager: Initializing...
INFO   | jvm 1    | 2010/12/19 00:11:17 | LOG4J: Configured Logging for: sagex-api using file: sagex-api.log4j.properties
INFO   | jvm 1    | 2010/12/19 00:11:17 | Embedded SageAPI is not functional.  We are most likely running remotely.
INFO   | jvm 1    | 2010/12/19 00:11:17 | Adding Remote Server: asrock
INFO   | jvm 1    | 2010/12/19 00:11:22 | SJQv4 Agent (Task Client) v4.0.0.1325
INFO   | jvm 1    | 2010/12/19 00:11:22 | 
INFO   | jvm 1    | 2010/12/19 00:11:22 | The following scripting engines are available in this task client:
INFO   | jvm 1    | 2010/12/19 00:11:22 | 	Mozilla Rhino/1.6 release 2 [js]
INFO   | jvm 1    | 2010/12/19 00:11:22 | 	Groovy Scripting Engine/2.0 [groovy]
INFO   | jvm 1    | 2010/12/19 00:11:22 | 
INFO   | jvm 1    | 2010/12/19 00:11:26 | Remote SageAPI is not functional.  Can't use server: rmi://asrock:1098
...
INFO   | jvm 1    | 2010/12/19 09:05:35 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:05:35 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:05:35 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:05:35 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:05:36 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:05:36 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
The "remote sageapi is not functional" made me think of windows firewall. I also saw the sagex-api.log that had a stacktrace that seemed to confirm this. Here's an example:

Code:
2010-12-19 09:22:14,562 [Thread-2] INFO  sagex.remote.server.SimpleDatagramClient - Starting Datagram Client on 228.5.6.7:9998
2010-12-19 09:22:19,562 [Timer-0] INFO  sagex.remote.server.SimpleDatagramClient - Killing Datagram client after timeout
2010-12-19 09:22:19,593 [WrapperSimpleAppMain] WARN  sagex.SageAPI - No Remote Provider, using Null API Provider (this is ok some times).
2010-12-19 09:22:19,593 [WrapperSimpleAppMain] INFO  sagex.SageAPI - Sage Provider Implementation: sagex.stub.NullSageAPIProvider; null://
2010-12-19 09:22:35,718 [Thread-2] WARN  sagex.SageAPI - Discovery Error
java.lang.RuntimeException: Remote SageAPI is not functional.  Can't use server: rmi://asrock:1098
	at sagex.remote.rmi.RMISageAPI.<init>(RMISageAPI.java:28)
	at sagex.SageAPI.addRemoteProvider(SageAPI.java:353)
	at sagex.SageAPI$2.onDatagramPacketReceived(SageAPI.java:374)
	at sagex.remote.server.SimpleDatagramClient$1.run(SimpleDatagramClient.java:43)
	at java.lang.Thread.run(Unknown Source)
Caused by: java.rmi.ConnectException: Connection refused to host: asrock; nested exception is: 
	java.net.ConnectException: Connection timed out: connect
	at sun.rmi.transport.tcp.TCPEndpoint.newSocket(Unknown Source)
	at sun.rmi.transport.tcp.TCPChannel.createConnection(Unknown Source)
	at sun.rmi.transport.tcp.TCPChannel.newConnection(Unknown Source)
	at sun.rmi.server.UnicastRef.newCall(Unknown Source)
	at sun.rmi.registry.RegistryImpl_Stub.lookup(Unknown Source)
	at sagex.remote.rmi.RMISageAPI.callService(RMISageAPI.java:36)
	at sagex.remote.rmi.RMISageAPI.callService(RMISageAPI.java:52)
	at sagex.remote.rmi.RMISageAPI.<init>(RMISageAPI.java:25)
	... 4 more
Caused by: java.net.ConnectException: Connection timed out: connect
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.PlainSocketImpl.doConnect(Unknown Source)
	at java.net.PlainSocketImpl.connectToAddress(Unknown Source)
	at java.net.PlainSocketImpl.connect(Unknown Source)
	at java.net.SocksSocketImpl.connect(Unknown Source)
	at java.net.Socket.connect(Unknown Source)
	at java.net.Socket.connect(Unknown Source)
	at java.net.Socket.<init>(Unknown Source)
	at java.net.Socket.<init>(Unknown Source)
	at sun.rmi.transport.proxy.RMIDirectSocketFactory.createSocket(Unknown Source)
	at sun.rmi.transport.proxy.RMIMasterSocketFactory.createSocket(Unknown Source)
	... 12 more
2010-12-19 09:22:35,718 [Thread-2] INFO  sagex.remote.server.SimpleDatagramClient - Datagram Client is shutting down
Since the log above said "rmi://asrock:1098" I opened port 1098 on the server. That didn't work. Most likely Java is redirecting to another port that isn't open. http://download.oracle.com/javase/6/....html#firewall

So next I tried disabling the firewall on both side. I hate to do this, but I'm trying to debug. I fired off another manual task and it failed without logs. Here is sagex-api.log on my desktop computer:

Code:
2010-12-19 09:32:41,765 [Thread-2] INFO  sagex.remote.server.SimpleDatagramClient - Starting Datagram Client on 228.5.6.7:9998
2010-12-19 09:32:46,765 [Timer-0] INFO  sagex.remote.server.SimpleDatagramClient - Killing Datagram client after timeout
2010-12-19 09:32:46,765 [Thread-2] WARN  sagex.remote.server.SimpleDatagramClient - Shutting Down: socket closed
2010-12-19 09:32:46,765 [Thread-2] INFO  sagex.remote.server.SimpleDatagramClient - Datagram Client is shutting down
2010-12-19 09:32:46,796 [WrapperSimpleAppMain] WARN  sagex.SageAPI - No Remote Provider, using Null API Provider (this is ok some times).
2010-12-19 09:32:46,796 [WrapperSimpleAppMain] INFO  sagex.SageAPI - Sage Provider Implementation: sagex.stub.NullSageAPIProvider; null://
Here's wrapper.log on my desktop computer:

Code:
STATUS | wrapper  | 2010/12/19 09:32:41 | --> Wrapper Started as Service
STATUS | wrapper  | 2010/12/19 09:32:41 | Java Service Wrapper Community Edition 32-bit 3.5.6
STATUS | wrapper  | 2010/12/19 09:32:41 |   Copyright (C) 1999-2010 Tanuki Software, Ltd. All Rights Reserved.
STATUS | wrapper  | 2010/12/19 09:32:41 |     http://wrapper.tanukisoftware.com
STATUS | wrapper  | 2010/12/19 09:32:41 | 
STATUS | wrapper  | 2010/12/19 09:32:41 | Launching a JVM...
INFO   | jvm 1    | 2010/12/19 09:32:41 | WrapperManager: Initializing...
INFO   | jvm 1    | 2010/12/19 09:32:41 | LOG4J: Configured Logging for: sagex-api using file: sagex-api.log4j.properties
INFO   | jvm 1    | 2010/12/19 09:32:41 | Embedded SageAPI is not functional.  We are most likely running remotely.
INFO   | jvm 1    | 2010/12/19 09:32:46 | SJQv4 Agent (Task Client) v4.0.0.1325
INFO   | jvm 1    | 2010/12/19 09:32:46 | 
INFO   | jvm 1    | 2010/12/19 09:32:46 | The following scripting engines are available in this task client:
INFO   | jvm 1    | 2010/12/19 09:32:46 | 	Mozilla Rhino/1.6 release 2 [js]
INFO   | jvm 1    | 2010/12/19 09:32:46 | 	Groovy Scripting Engine/2.0 [groovy]
INFO   | jvm 1    | 2010/12/19 09:32:46 | 
INFO   | jvm 1    | 2010/12/19 09:34:04 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:34:04 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:34:04 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:34:04 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:34:05 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
INFO   | jvm 1    | 2010/12/19 09:34:05 | log4j:ERROR Attempted to append to closed appender named [sjqAgentApp].
Next I edited the log4j properties and changed the logging specifications at the top to this:

Code:
log4j.rootLogger=INFO, sjqAgentApp
log4j.rootLogger=WARN, sjqAgentApp
log4j.rootLogger=ERROR, sjqAgentApp
That finally cause this to appear in my agent log:

Code:
2010-12-19 09:47:48,843 ERROR [192_168_1_4-23347-75]: Unable to execute 'G:\Mediashrink\Mediashrink.exe'; marking task as FAILED!
I'll investigate that next. I do wonder though why the logging configuration isn't working for me.
Reply With Quote
  #3  
Old 12-19-2010, 09:05 AM
coppit coppit is offline
Sage Advanced User
 
Join Date: Mar 2003
Posts: 176
Next I wondered why it was saying "asrock". I pinged asrock in my command shell and my desktop machine was not properly resolving "asrock" to 192.168.1.4. So I edited C:\Windows\system32\drivers\etc\hosts and ping worked.

I restarted sjqagent and tried another manual task. The sagex-api.log has this now:

Code:
2010-12-19 09:59:49,031 [Thread-2] INFO  sagex.remote.server.SimpleDatagramClient - Starting Datagram Client on 228.5.6.7:9998
2010-12-19 09:59:49,437 [WrapperSimpleAppMain] INFO  sagex.SageAPI - Sage Provider Implementation: sagex.remote.rmi.RMISageAPI; rmi://asrock:1098
2010-12-19 09:59:54,031 [Timer-0] INFO  sagex.remote.server.SimpleDatagramClient - Killing Datagram client after timeout
2010-12-19 09:59:54,031 [Thread-2] WARN  sagex.remote.server.SimpleDatagramClient - Shutting Down: socket closed
2010-12-19 09:59:54,031 [Thread-2] INFO  sagex.remote.server.SimpleDatagramClient - Datagram Client is shutting dow
Why is it trying 228.5.6.7? When I run tracert on it I get this:

Code:
Tracing route to reserved-multicast-range-NOT-delegated.example.com [228.5.6.7]
over a maximum of 30 hops:
Something seems fundamentally busted.
Reply With Quote
  #4  
Old 12-19-2010, 09:57 AM
Slugger Slugger is offline
SageTVaholic
 
Join Date: Mar 2007
Location: Kingston, ON
Posts: 4,008
There is a bug with the log config for the Windows service client. The fix is in this post:

http://forums.sagetv.com/forums/show...1&postcount=96

Fix the logging issues and then try to get your task working again. Since you're accessing data from a network share, you must change the user the service runs as from LocalSystem to an actual account with network access (usually your login id/pwd). Also, I don't believe windows services can access mapped network drives; you will want to change the paths to UNC.

Reset all the config, try again, report back errors.
__________________
Twitter: @ddb_db
Server: Intel i5-4570 Quad Core, 16GB RAM, 1 x 128GB OS SSD (Win7 Pro x64 SP1), 1 x 2TB media drive
Capture: 2 x Colossus
STB Controller: 1 x USB-UIRT
Software:Java 1.7.0_71; SageTV 7.1.9
Clients: 1 x HD300, 2 x HD200, 1 x SageClient, 1 x PlaceShifter
Plugins: Too many to list now...
Reply With Quote
  #5  
Old 12-19-2010, 11:03 AM
coppit coppit is offline
Sage Advanced User
 
Join Date: Mar 2003
Posts: 176
Awesome, thanks. I used UNC paths like \\192.168.1.4\data\MediaShrink\MediaShrink.exe and I see the task running on my machine now.
Reply With Quote
Reply


Currently Active Users Viewing This Thread: 1 (0 members and 1 guests)
 

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off

Forum Jump

Similar Threads
Thread Thread Starter Forum Replies Last Post
Plugin: SJQv4 Slugger SageTV v7 Customizations 1639 02-19-2022 03:04 PM
SJQv4: Technology Preview Slugger SageTV v7 Customizations 39 12-17-2010 01:17 PM
SJQv4: Design Discussion Slugger SageTV v7 Customizations 26 10-18-2010 08:22 AM
SagetTVService Virus Win32.Agent.dwo Ponchera SageTV Software 6 02-04-2008 06:33 PM
NVIDIA Boot Agent loads after Sage freezes; doesn't see hard drive popechild Hardware Support 8 08-24-2007 07:27 PM


All times are GMT -6. The time now is 01:24 PM.


Powered by vBulletin® Version 3.8.11
Copyright ©2000 - 2023, vBulletin Solutions Inc.
Copyright 2003-2005 SageTV, LLC. All rights reserved.