2011-02-03 10:06:50,263 INFO  [TaskQueue]: Assigned task 683 of type 'QUEUEMOVIES2MOVE' to Client[host=HTPC:23344,state=ONLINE,lastUpdate=Thu Feb 03 10:06:50 EST 2011]
2011-02-03 10:06:50,263 INFO  [Handler]: CMD: GETARGS :: PEER: /192.168.1.101
2011-02-03 10:06:50,263 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:06:50,264 WARN  [TaskQueue]: Returning 'null' for 683
2011-02-03 10:06:50,543 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:06:51,290 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:06:51,744 INFO  [Handler]: CMD: ADDTASK :: PEER: /192.168.1.101
2011-02-03 10:06:51,749 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:06:51,766 INFO  [Handler]: CMD: QUIT :: PEER: /192.168.1.101
2011-02-03 10:06:51,772 ERROR [Handler]: IOError
java.net.SocketException: Connection reset
	at java.net.SocketInputStream.read(Unknown Source)
	at java.net.SocketInputStream.read(Unknown Source)
	at java.io.ObjectInputStream$PeekInputStream.peek(Unknown Source)
	at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(Unknown Source)
	at java.io.ObjectInputStream$BlockDataInputStream.refill(Unknown Source)
	at java.io.ObjectInputStream$BlockDataInputStream.read(Unknown Source)
	at java.io.DataInputStream.readUnsignedShort(Unknown Source)
	at java.io.ObjectInputStream$BlockDataInputStream.readUnsignedShort(Unknown Source)
	at java.io.ObjectInputStream$BlockDataInputStream.readUTF(Unknown Source)
	at java.io.ObjectInputStream.readUTF(Unknown Source)
	at com.google.code.sagetvaddons.sjq.listener.Handler.run(Handler.java:62)
	at java.lang.Thread.run(Unknown Source)
2011-02-03 10:06:51,777 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:06:51,778 INFO  [Handler]: CMD: LOGEXE :: PEER: /192.168.1.101
2011-02-03 10:06:51,783 INFO  [Handler]: CMD: QUIT :: PEER: /192.168.1.101
2011-02-03 10:06:51,786 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:06:51,787 INFO  [Handler]: CMD: UPDATE :: PEER: /192.168.1.101
2011-02-03 10:06:51,791 INFO  [Handler]: CMD: QUIT :: PEER: /192.168.1.101
2011-02-03 10:06:54,426 INFO  [Handler]: CMD: QUIT :: PEER: /192.168.1.101
2011-02-03 10:06:59,147 ERROR [DataStore]: SQL Error
org.h2.jdbc.JdbcSQLException: The object is already closed [90007-145]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:327)
	at org.h2.message.DbException.get(DbException.java:167)
	at org.h2.message.DbException.get(DbException.java:144)
	at org.h2.message.DbException.get(DbException.java:133)
	at org.h2.jdbc.JdbcConnection.checkClosed(JdbcConnection.java:1330)
	at org.h2.jdbc.JdbcConnection.checkClosed(JdbcConnection.java:1308)
	at org.h2.jdbc.JdbcConnection.createStatement(JdbcConnection.java:164)
	at com.google.code.sagetvaddons.sjq.server.DataStore.getQueue(DataStore.java:513)
	at com.google.code.sagetvaddons.sjq.server.DataStore.getActiveQueue(DataStore.java:493)
	at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at sage.e$e.a(Unknown Source)
	at sage.a.m$b.a(Unknown Source)
	at sage.a.m.a(Unknown Source)
	at sage.e.a(Unknown Source)
	at sage.bc.a(Unknown Source)
	at sage.bc.a(Unknown Source)
	at sage.bc.a(Unknown Source)
	at sage.bc.a(Unknown Source)
	at sage.bc$2.run(Unknown Source)
	at sage.cv$a.run(Unknown Source)
2011-02-03 10:06:59,750 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:06:59,750 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:07:04,147 ERROR [DataStore]: SQL Error
org.h2.jdbc.JdbcSQLException: The object is already closed [90007-145]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:327)
	at org.h2.message.DbException.get(DbException.java:167)
	at org.h2.message.DbException.get(DbException.java:144)
	at org.h2.message.DbException.get(DbException.java:133)
	at org.h2.jdbc.JdbcConnection.checkClosed(JdbcConnection.java:1330)
	at org.h2.jdbc.JdbcConnection.checkClosed(JdbcConnection.java:1308)
	at org.h2.jdbc.JdbcConnection.createStatement(JdbcConnection.java:164)
	at com.google.code.sagetvaddons.sjq.server.DataStore.getQueue(DataStore.java:513)
	at com.google.code.sagetvaddons.sjq.server.DataStore.getActiveQueue(DataStore.java:493)
	at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at sage.e$e.a(Unknown Source)
	at sage.a.m$b.a(Unknown Source)
	at sage.a.m.a(Unknown Source)
	at sage.e.a(Unknown Source)
	at sage.bc.a(Unknown Source)
	at sage.bc.a(Unknown Source)
	at sage.bc.a(Unknown Source)
	at sage.bc.a(Unknown Source)
	at sage.bc$2.run(Unknown Source)
	at sage.cv$a.run(Unknown Source)
2011-02-03 10:07:05,238 WARN  [DataStore]: Problem connecting to database... trying again in 1 seconds...
2011-02-03 10:07:12,254 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:07:12,254 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:07:12,257 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:07:18,011 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:07:20,258 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:07:20,258 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:07:36,261 INFO  [Handler]: CMD: QUIT :: PEER: /192.168.1.101
2011-02-03 10:07:42,258 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:07:45,645 WARN  [DataStore]: Problem connecting to database... trying again in 1 seconds...
2011-02-03 10:07:46,652 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:07:50,259 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:07:50,259 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:08:01,659 INFO  [Handler]: CMD: PINGC :: PEER: /192.168.1.101
2011-02-03 10:08:01,660 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:06:50.258]
2011-02-03 10:08:01,665 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:08:12,254 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:08:12,254 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:08:12,258 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:08:20,258 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:08:20,258 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:08:21,577 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:08:30,746 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:08:30,746 WARN  [DataStore]: Problem connecting to database... trying again in 1 seconds...
2011-02-03 10:08:32,334 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:08:32,945 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:08:33,399 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:08:33,967 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:08:36,577 INFO  [Handler]: CMD: PINGC :: PEER: /192.168.1.101
2011-02-03 10:08:36,578 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:08:01.665]
2011-02-03 10:08:36,583 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:08:40,263 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:08:36.584]
2011-02-03 10:08:40,266 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:08:42,258 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:08:47,339 INFO  [Handler]: CMD: PINGC :: PEER: /192.168.1.101
2011-02-03 10:08:47,339 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:08:01.665]
2011-02-03 10:08:47,341 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:08:47,950 INFO  [Handler]: CMD: PINGC :: PEER: /192.168.1.101
2011-02-03 10:08:47,950 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:08:01.665]
2011-02-03 10:08:47,952 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:08:48,404 INFO  [Handler]: CMD: PINGC :: PEER: /192.168.1.101
2011-02-03 10:08:48,404 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:08:01.665]
2011-02-03 10:08:48,406 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:08:48,972 INFO  [Handler]: CMD: PINGC :: PEER: /192.168.1.101
2011-02-03 10:08:48,972 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:08:01.665]
2011-02-03 10:08:48,974 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:08:50,258 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:08:50,258 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:09:12,256 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:09:12,256 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:09:12,258 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:09:20,259 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:09:20,259 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:09:42,259 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:09:50,260 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:09:50,260 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:10:12,256 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:10:12,256 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:10:12,259 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:10:20,259 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:10:20,259 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:10:40,263 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:08:48.974]
2011-02-03 10:10:40,265 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:10:42,259 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:10:50,260 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:10:50,260 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:11:12,258 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:11:12,258 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:11:12,259 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:11:20,260 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:11:20,260 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:11:42,260 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:11:50,260 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:11:50,260 WARN  [TaskQueue]: No clients available to accept task of type 'MVMEDIA'
2011-02-03 10:12:02,986 INFO  [Listener]: Received connection from: /192.168.1.101
2011-02-03 10:12:02,986 INFO  [Handler]: CMD: RMTASK :: PEER: /192.168.1.101
2011-02-03 10:12:12,258 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:12:12,258 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:12:12,260 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:12:20,260 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:12:40,263 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:10:40.265]
2011-02-03 10:12:40,266 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:12:42,260 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:12:50,261 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:13:12,259 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:13:12,259 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:13:12,260 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:13:20,261 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:13:42,261 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:13:50,261 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:14:12,261 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:14:12,261 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:14:12,261 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:14:20,261 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:14:40,263 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:12:40.266]
2011-02-03 10:14:40,266 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:14:42,261 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:14:50,262 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:14:58,321 INFO  [Scanmedia]: Media scan started!
2011-02-03 10:15:12,262 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:15:12,262 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:15:12,262 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:15:20,262 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:15:42,263 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:15:50,263 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:16:12,261 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:16:12,262 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:16:12,263 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:16:20,264 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:16:40,264 INFO  [AgentManager]: Pinging Client[host=HTPC:23344,state=ONLINE,lastUpdate=2011-02-03 10:14:40.266]
2011-02-03 10:16:40,266 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:16:42,263 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2011-02-03 10:16:50,264 INFO  [TaskQueue]: Running queue processor now!
2011-02-03 10:17:12,263 INFO  [ListenerClient]: Disconnected from HTPC:23344
2011-02-03 10:17:12,263 INFO  [ActiveTaskManager]: Validated 1 running task(s)!
2011-02-03 10:17:12,263 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!