[mythtv-users] MythTV is locked by a user

Mark Greenwood fatgerman at ntlworld.com
Sat Jul 5 19:11:18 UTC 2008


Mythwelcome has started displaying this message. The box has auto-started to record a program, finished the recording but then remains stuck in this state, and it won't let the box shut down. There are no frontend clients connected, so this message would seem to be incorrect.

I'd post the backend log here but it's rather long. However there are several entries like the following:

2008-07-05 18:31:15.536 DB Error (change_program):
Query was:
UPDATE program SET starttime = '2008-07-05T13:25:00',     endtime   = '2008-07-05T14:00:00' WHERE chanid    = 1013 AND       starttime = '2008-07-05T13:20:00'
Driver error was [2/1062]:
QMYSQL3: Unable to execute query
Database error was:
Duplicate entry '1013-2008-07-05 13:25:00-0' for key 1


..and here's the end of the log

2008-07-05 19:54:38.625 I'm idle now... shutdown will occur in 120 seconds.
2008-07-05 19:55:17.554 Reschedule requested for id -1.
2008-07-05 19:55:18.173 Scheduled 53 items in 0.6 = 0.06 match + 0.52 place
2008-07-05 19:55:18.226 scheduler: Scheduled items: Scheduled 53 items in 0.6 = 0.06 match + 0.52 place
2008-07-05 19:55:19.264 I'm idle now... shutdown will occur in 120 seconds.
2008-07-05 19:56:15.644 MainServer::HandleAnnounce Playback
2008-07-05 19:56:15.649 adding: newboy as a client (events: 0)
2008-07-05 19:56:15.651 MainServer::HandleAnnounce Monitor
2008-07-05 19:56:15.652 adding: newboy as a client (events: 1)
2008-07-05 19:56:27.277 I'm idle now... shutdown will occur in 120 seconds.
2008-07-05 19:58:26.546 Using runtime prefix = /usr, libdir = /usr/lib
2008-07-05 19:58:26.552 Empty LocalHostName.
2008-07-05 19:58:26.553 Using localhost value of newboy
2008-07-05 19:58:26.556 MCP::DefaultUPnP() - No default UPnP backend
2008-07-05 19:58:26.569 New DB connection, total: 1
2008-07-05 19:58:26.576 Connected to database 'mythconverg' at host: localhost
2008-07-05 19:58:26.579 Closing DB connection named 'DBManager0'
2008-07-05 19:58:26.580 Clearing Settings Cache.
2008-07-05 19:58:26.581 Enabling Settings Cache.
2008-07-05 19:58:26.582 Clearing Settings Cache.
2008-07-05 19:58:26.582 Mythshutdown: --check
2008-07-05 19:58:26.583 Mythshutdown: --status
2008-07-05 19:58:26.634 isRecording: Attempting to connect to master server...
2008-07-05 19:58:26.636 Connected to database 'mythconverg' at host: localhost
2008-07-05 19:58:26.640 MSqlQuery: SELECT data FROM settings WHERE value = 'MasterServerIP' AND hostname = 'newboy' ;
2008-07-05 19:58:26.642 MSqlQuery: SELECT data FROM settings WHERE value = 'MasterServerIP' AND hostname IS NULL;
2008-07-05 19:58:26.644 MSqlQuery: SELECT data FROM settings WHERE value = 'MasterServerPort' AND hostname = 'newboy' ;
2008-07-05 19:58:26.647 MSqlQuery: SELECT data FROM settings WHERE value = 'MasterServerPort' AND hostname IS NULL;
2008-07-05 19:58:26.648 MythSocket(8140928:4): new socket
2008-07-05 19:58:26.651 MSqlQuery: SELECT data FROM settings WHERE value = 'WOLbackendReconnectWaitTime' AND hostname = 'newboy' ;
2008-07-05 19:58:26.653 MSqlQuery: SELECT data FROM settings WHERE value = 'WOLbackendReconnectWaitTime' AND hostname IS NULL;
2008-07-05 19:58:26.658 MSqlQuery: SELECT data FROM settings WHERE value = 'WOLbackendConnectRetry' AND hostname = 'newboy' ;
2008-07-05 19:58:26.667 MSqlQuery: SELECT data FROM settings WHERE value = 'WOLbackendConnectRetry' AND hostname IS NULL;
2008-07-05 19:58:26.668 Connecting to backend server: 192.168.1.4:6543 (try 1 of 5)
2008-07-05 19:58:26.669 MythSocket(8140f00:5): new socket
2008-07-05 19:58:26.669 MythSocket(8140f00:5): attempting connect() to (192.168.1.4:6543)
2008-07-05 19:58:26.671 MythSocket(8140f00:5): state change Idle -> Connected
2008-07-05 19:58:26.672 write ->  5 21      MYTH_PROTO_VERSION 40
2008-07-05 19:58:26.674 read  <-  5 13      ACCEPT[]:[]40
2008-07-05 19:58:26.675 Using protocol version 40
2008-07-05 19:58:26.675 write ->  5 20      ANN Monitor newboy 0
2008-07-05 19:58:26.677 MainServer::HandleAnnounce Monitor
2008-07-05 19:58:26.680 adding: newboy as a client (events: 0)
2008-07-05 19:58:26.681 read  <-  5 2       OK
2008-07-05 19:58:26.685 MythSocket(8140928:4): attempting connect() to (192.168.1.4:6543)
2008-07-05 19:58:26.686 MythSocket(8140928:4): state change Idle -> Connected
2008-07-05 19:58:26.687 write ->  4 20      ANN Monitor newboy 1
2008-07-05 19:58:26.688 MainServer::HandleAnnounce Monitor
2008-07-05 19:58:26.691 adding: newboy as a client (events: 1)
2008-07-05 19:58:26.692 read  <-  4 2       OK
2008-07-05 19:58:26.695 MythSocket: readyread thread start
2008-07-05 19:58:26.695 MythSocket(8140928:4): UpRef: 1
2008-07-05 19:58:26.704 MSqlQuery: SELECT cardid FROM capturecard ORDER BY cardid
2008-07-05 19:58:26.705 write ->  5 35      QUERY_REMOTEENCODER 1[]:[]GET_STATE
2008-07-05 19:58:26.707 read  <-  5 1       0
2008-07-05 19:58:26.708 write ->  5 35      QUERY_REMOTEENCODER 3[]:[]GET_STATE
2008-07-05 19:58:26.709 read  <-  5 1       0
2008-07-05 19:58:26.710 write ->  5 35      QUERY_REMOTEENCODER 4[]:[]GET_STATE
2008-07-05 19:58:26.711 MainServer: HandleRemoteEncoder(cmd GET_STATE) Unknown encoder: 4
2008-07-05 19:58:26.716 read  <-  5 2       -1
2008-07-05 19:58:26.720 MSqlQuery: SELECT data FROM settings WHERE value = 'MythShutdownLock' AND hostname IS NULL;
2008-07-05 19:58:26.721 Shutdown is locked
2008-07-05 19:58:26.723 MSqlQuery: SELECT data FROM settings WHERE value = 'JobQueueWindowStart' AND hostname = 'newboy' ;
2008-07-05 19:58:26.725 MSqlQuery: SELECT data FROM settings WHERE value = 'JobQueueWindowEnd' AND hostname = 'newboy' ;
2008-07-05 19:58:26.726 JobQueue: Currently set to run new jobs from 00:00 to 23:59
2008-07-05 19:58:26.727 JobQueue: HasRunningOrPendingJobs: checking for jobs starting before: Sat Jul 5 20:13:26 2008
2008-07-05 19:58:26.729 New DB connection, total: 2
2008-07-05 19:58:26.731 Connected to database 'mythconverg' at host: localhost
2008-07-05 19:58:26.733 MSqlQuery: SELECT data FROM settings WHERE value = 'AutoCommflagWhileRecording' AND hostname = 'newboy' ;
2008-07-05 19:58:26.734 MSqlQuery: SELECT data FROM settings WHERE value = 'AutoCommflagWhileRecording' AND hostname IS NULL;
2008-07-05 19:58:26.736 MSqlQuery: SELECT j.id, j.chanid, j.starttime, j.inserttime, j.type, j.cmds, j.flags, j.status, j.statustime, j.hostname, j.args, j.comment, r.endtime, j.schedruntime FROM jobqueue j, recorded r WHERE j.chanid = r.chanid AND j.starttime = r.starttime ORDER BY j.inserttime, j.chanid, j.id;
2008-07-05 19:58:26.737 JobQueue: GetJobsInQueue: findJobs search bitmask 4, found 0 total jobs
2008-07-05 19:58:26.738 MSqlQuery: SELECT data FROM settings WHERE value = 'DailyWakeupStartPeriod1' AND hostname IS NULL;
2008-07-05 19:58:26.740 MSqlQuery: SELECT data FROM settings WHERE value = 'DailyWakeupEndPeriod1' AND hostname IS NULL;
2008-07-05 19:58:26.742 MSqlQuery: SELECT data FROM settings WHERE value = 'DailyWakeupStartPeriod2' AND hostname IS NULL;
2008-07-05 19:58:26.743 MSqlQuery: SELECT data FROM settings WHERE value = 'DailyWakeupEndPeriod2' AND hostname IS NULL;
2008-07-05 19:58:26.761 Mythshutdown: --status returned: 16
2008-07-05 19:58:26.762 Not OK to shutdown
2008-07-05 19:58:26.763 Mythshutdown: --check returned: 1
2008-07-05 19:58:26.765 MythSocket: readyread thread exit
2008-07-05 19:58:28.776 I'm idle now... shutdown will occur in 120 seconds.
2008-07-05 19:59:22.166 UPnpMedia: BuildMediaMap VIDEO scan starting in :/home/bob/Videos:
2008-07-05 19:59:22.177 UPnpMedia: BuildMediaMap Done. Found 0 objects
2008-07-05 19:59:29.172 Reschedule requested for id -1.
2008-07-05 19:59:29.865 Scheduled 53 items in 0.7 = 0.34 match + 0.35 place
2008-07-05 19:59:29.873 scheduler: Scheduled items: Scheduled 53 items in 0.7 = 0.34 match + 0.35 place
2008-07-05 19:59:30.876 I'm idle now... shutdown will occur in 120 seconds.
2008-07-05 20:00:03.241 MainServer::HandleAnnounce Monitor
2008-07-05 20:00:03.243 adding: newboy as a client (events: 0)
2008-07-05 20:00:22.531 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2008-07-05 20:01:30.248 Using runtime prefix = /usr, libdir = /usr/lib
2008-07-05 20:01:30.252 Empty LocalHostName.
2008-07-05 20:01:30.253 Using localhost value of newboy
2008-07-05 20:01:30.255 MCP::DefaultUPnP() - No default UPnP backend
2008-07-05 20:01:30.268 New DB connection, total: 1
2008-07-05 20:01:30.275 Connected to database 'mythconverg' at host: localhost
2008-07-05 20:01:30.277 Closing DB connection named 'DBManager0'
2008-07-05 20:01:30.279 Clearing Settings Cache.
2008-07-05 20:01:30.279 Enabling Settings Cache.
2008-07-05 20:01:30.280 Clearing Settings Cache.
2008-07-05 20:01:30.281 Mythshutdown: --check
2008-07-05 20:01:30.281 Mythshutdown: --status
2008-07-05 20:01:30.339 isRecording: Attempting to connect to master server...
2008-07-05 20:01:30.340 Connected to database 'mythconverg' at host: localhost
2008-07-05 20:01:30.343 MSqlQuery: SELECT data FROM settings WHERE value = 'MasterServerIP' AND hostname = 'newboy' ;
2008-07-05 20:01:30.344 MSqlQuery: SELECT data FROM settings WHERE value = 'MasterServerIP' AND hostname IS NULL;
2008-07-05 20:01:30.347 MSqlQuery: SELECT data FROM settings WHERE value = 'MasterServerPort' AND hostname = 'newboy' ;
2008-07-05 20:01:30.348 MSqlQuery: SELECT data FROM settings WHERE value = 'MasterServerPort' AND hostname IS NULL;
2008-07-05 20:01:30.350 MythSocket(8140928:4): new socket
2008-07-05 20:01:30.351 MSqlQuery: SELECT data FROM settings WHERE value = 'WOLbackendReconnectWaitTime' AND hostname = 'newboy' ;
2008-07-05 20:01:30.352 MSqlQuery: SELECT data FROM settings WHERE value = 'WOLbackendReconnectWaitTime' AND hostname IS NULL;
2008-07-05 20:01:30.354 MSqlQuery: SELECT data FROM settings WHERE value = 'WOLbackendConnectRetry' AND hostname = 'newboy' ;
2008-07-05 20:01:30.355 MSqlQuery: SELECT data FROM settings WHERE value = 'WOLbackendConnectRetry' AND hostname IS NULL;
2008-07-05 20:01:30.356 Connecting to backend server: 192.168.1.4:6543 (try 1 of 5)
2008-07-05 20:01:30.357 MythSocket(8140d60:5): new socket
2008-07-05 20:01:30.358 MythSocket(8140d60:5): attempting connect() to (192.168.1.4:6543)
2008-07-05 20:01:30.360 MythSocket(8140d60:5): state change Idle -> Connected
2008-07-05 20:01:30.361 write ->  5 21      MYTH_PROTO_VERSION 40
2008-07-05 20:01:30.362 read  <-  5 13      ACCEPT[]:[]40
2008-07-05 20:01:30.363 Using protocol version 40
2008-07-05 20:01:30.363 write ->  5 20      ANN Monitor newboy 0
2008-07-05 20:01:30.364 MainServer::HandleAnnounce Monitor
2008-07-05 20:01:30.367 adding: newboy as a client (events: 0)
2008-07-05 20:01:30.368 read  <-  5 2       OK
2008-07-05 20:01:30.371 MythSocket(8140928:4): attempting connect() to (192.168.1.4:6543)
2008-07-05 20:01:30.372 MythSocket(8140928:4): state change Idle -> Connected
2008-07-05 20:01:30.374 write ->  4 20      ANN Monitor newboy 1
2008-07-05 20:01:30.375 MainServer::HandleAnnounce Monitor
2008-07-05 20:01:30.379 adding: newboy as a client (events: 1)
2008-07-05 20:01:30.380 read  <-  4 2       OK
2008-07-05 20:01:30.383 MythSocket: readyread thread start
2008-07-05 20:01:30.383 MythSocket(8140928:4): UpRef: 1
2008-07-05 20:01:30.392 MSqlQuery: SELECT cardid FROM capturecard ORDER BY cardid
2008-07-05 20:01:30.393 write ->  5 35      QUERY_REMOTEENCODER 1[]:[]GET_STATE
2008-07-05 20:01:30.395 read  <-  5 1       0
2008-07-05 20:01:30.396 write ->  5 35      QUERY_REMOTEENCODER 3[]:[]GET_STATE
2008-07-05 20:01:30.397 read  <-  5 1       0
2008-07-05 20:01:30.399 write ->  5 35      QUERY_REMOTEENCODER 4[]:[]GET_STATE
2008-07-05 20:01:30.400 MainServer: HandleRemoteEncoder(cmd GET_STATE) Unknown encoder: 4
2008-07-05 20:01:30.403 read  <-  5 2       -1
2008-07-05 20:01:30.408 MSqlQuery: SELECT data FROM settings WHERE value = 'MythShutdownLock' AND hostname IS NULL;
2008-07-05 20:01:30.409 Shutdown is locked
2008-07-05 20:01:30.411 MSqlQuery: SELECT data FROM settings WHERE value = 'JobQueueWindowStart' AND hostname = 'newboy' ;
2008-07-05 20:01:30.412 MSqlQuery: SELECT data FROM settings WHERE value = 'JobQueueWindowEnd' AND hostname = 'newboy' ;
2008-07-05 20:01:30.413 JobQueue: Currently set to run new jobs from 00:00 to 23:59
2008-07-05 20:01:30.414 JobQueue: HasRunningOrPendingJobs: checking for jobs starting before: Sat Jul 5 20:16:30 2008
2008-07-05 20:01:30.417 New DB connection, total: 2
2008-07-05 20:01:30.418 Connected to database 'mythconverg' at host: localhost
2008-07-05 20:01:30.420 MSqlQuery: SELECT data FROM settings WHERE value = 'AutoCommflagWhileRecording' AND hostname = 'newboy' ;
2008-07-05 20:01:30.421 MSqlQuery: SELECT data FROM settings WHERE value = 'AutoCommflagWhileRecording' AND hostname IS NULL;
2008-07-05 20:01:30.423 MSqlQuery: SELECT j.id, j.chanid, j.starttime, j.inserttime, j.type, j.cmds, j.flags, j.status, j.statustime, j.hostname, j.args, j.comment, r.endtime, j.schedruntime FROM jobqueue j, recorded r WHERE j.chanid = r.chanid AND j.starttime = r.starttime ORDER BY j.inserttime, j.chanid, j.id;
2008-07-05 20:01:30.424 JobQueue: GetJobsInQueue: findJobs search bitmask 4, found 0 total jobs
2008-07-05 20:01:30.425 MSqlQuery: SELECT data FROM settings WHERE value = 'DailyWakeupStartPeriod1' AND hostname IS NULL;
2008-07-05 20:01:30.427 MSqlQuery: SELECT data FROM settings WHERE value = 'DailyWakeupEndPeriod1' AND hostname IS NULL;
2008-07-05 20:01:30.429 MSqlQuery: SELECT data FROM settings WHERE value = 'DailyWakeupStartPeriod2' AND hostname IS NULL;
2008-07-05 20:01:30.430 MSqlQuery: SELECT data FROM settings WHERE value = 'DailyWakeupEndPeriod2' AND hostname IS NULL;
2008-07-05 20:01:30.448 Mythshutdown: --status returned: 16
2008-07-05 20:01:30.449 Not OK to shutdown
2008-07-05 20:01:30.450 Mythshutdown: --check returned: 1
2008-07-05 20:01:30.453 MythSocket: readyread thread exit
2008-07-05 20:01:32.464 I'm idle now... shutdown will occur in 120 seconds.


Thanks,

Mark


More information about the mythtv-users mailing list