[mythtv-users] 0.25.0~master.20120314.c09b076 db crash error

Steven Adeff adeffs.mythtv at gmail.com
Wed Mar 14 12:21:28 UTC 2012


The problem looks to have started here:
Mar 14 07:02:45 mythbackend mythbackend[28125]: I ProcessRequest mainserver.cpp:
1358 (HandleAnnounce) MainServer::ANN Monitor
Mar 14 07:02:45 mythbackend mythbackend[28125]: I ProcessRequest mainserver.cpp:
1358 (HandleAnnounce) MainServer::ANN Monitor
Mar 14 07:02:45 mythbackend mythbackend[28125]: I ProcessRequest mainserver.cpp:
1360 (HandleAnnounce) adding: mythbackend as a client (events: 0)
Mar 14 07:02:45 mythbackend mythbackend[28125]: I ProcessRequest mainserver.cpp:
1360 (HandleAnnounce) adding: mythbackend as a client (events: 0)
Mar 14 07:02:45 mythbackend mythbackend[28125]: I ProcessRequest mainserver.cpp:
1358 (HandleAnnounce) MainServer::ANN Monitor
Mar 14 07:02:45 mythbackend mythbackend[28125]: I ProcessRequest mainserver.cpp:
1360 (HandleAnnounce) adding: mythbackend as a client (events: 1)
Mar 14 07:02:45 mythbackend mythbackend[28125]: I ProcessRequest mainserver.cpp:
1358 (HandleAnnounce) MainServer::ANN Monitor
Mar 14 07:02:45 mythbackend mythbackend[28125]: I ProcessRequest mainserver.cpp:
1360 (HandleAnnounce) adding: mythbackend as a client (events: 1)
Mar 14 07:02:53 mythbackend mythbackend[30762]: C thread_unknown mythcommandline
parser.cpp:2534 (ConfigureLogging) mythbackend version: master [v0.25-beta-99-gf
f73126] www.mythtv.org
Mar 14 07:02:53 mythbackend mythbackend[30762]: N thread_unknown mythcommandline
parser.cpp:2536 (ConfigureLogging) Enabled verbose msgs:  general
Mar 14 07:02:53 mythbackend mythbackend[30762]: I thread_unknown logging.cpp:229
 (FileLogger) Added logging to the console
Mar 14 07:02:53 mythbackend mythbackend[30762]: I thread_unknown logging.cpp:369
 (SyslogLogger) Added syslogging to facility local7
Mar 14 07:02:53 mythbackend mythbackend[30762]: I thread_unknown logging.cpp:425
 (DatabaseLogger) Added database logging to table logging
Mar 14 07:02:53 mythbackend mythbackend[30762]: N thread_unknown logging.cpp:120
9 (logStart) Setting up SIGHUP handler
Mar 14 07:02:53 mythbackend mythbackend[30762]: N thread_unknown mythdirs.cpp:51
 (InitializeMythDirs) Using runtime prefix = /usr
Mar 14 07:02:53 mythbackend mythbackend[30762]: N thread_unknown mythdirs.cpp:64
 (InitializeMythDirs) Using configuration directory = /home/mythtv/.mythtv
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythcontext.cpp:48
1 (LoadDatabaseSettings) Using localhost value of mythbackend
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythcontext.cpp:60
8 (TestDBconnection) Testing network connectivity to '192.168.1.151'
Mar 14 07:02:53 mythbackend mythbackend[30762]: I SystemManager system-unix.cpp:
263 (run) Starting process manager
Mar 14 07:02:53 mythbackend mythbackend[30762]: I SystemIOHandlerR system-unix.c
pp:90 (run) Starting IO manager (read)
Mar 14 07:02:53 mythbackend mythbackend[30762]: I SystemIOHandlerW system-unix.c
pp:90 (run) Starting IO manager (write)
Mar 14 07:02:53 mythbackend mythbackend[30762]: I SystemSignalManager system-uni
x.cpp:485 (run) Starting process signal handler
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythdbcon.cpp:75 (
MSqlDatabase) Database connection created: DBManager0
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythdbcon.cpp:298
(popConnection) New DB connection, total: 1
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythdbcon.cpp:179
(OpenDatabase) Connected to database 'mythconverg' at host: 192.168.1.151
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythdbcon.cpp:453
(CloseDatabases) Closing DB connection named 'DBManager0'
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythdbcon.cpp:75 (
MSqlDatabase) Database connection created: DBManager1
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythdbcon.cpp:298
(popConnection) New DB connection, total: 1
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythdbcon.cpp:179
(OpenDatabase) Connected to database 'mythconverg' at host: 192.168.1.151
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythcorecontext.cp
p:1272 (SaveLocaleDefaults) Current locale EN_US
Mar 14 07:02:53 mythbackend mythbackend[30762]: N CoreContext mythlocale.cpp:110
 (LoadDefaultsFromXML) Reading locale defaults from /usr/share/mythtv//locales/e
n_us.xml
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext schemawizard.cpp:1
17 (Compare) Current MythTV Schema Version (DBSchemaVer): 1299
Mar 14 07:02:53 mythbackend mythbackend[30762]: I CoreContext mythtranslation.cp
p:66 (load) Loading en_us translation for module mythfrontend
Mar 14 07:02:53 mythbackend mythbackend[30762]: N CoreContext main_helpers.cpp:5
56 (run_backend) MythBackend: Starting up as the master server.
Mar 14 07:02:53 mythbackend mythbackend[30762]: I DBLogger mythdbcon.cpp:75 (MSq
lDatabase) Database connection created: DBManager2
Mar 14 07:02:53 mythbackend mythbackend[30762]: I DBLogger mythdbcon.cpp:298 (po
pConnection) New DB connection, total: 2
Mar 14 07:02:53 mythbackend mythbackend[30762]: I DBLogger mythdbcon.cpp:179 (Op
enDatabase) Connected to database 'mythconverg' at host: 192.168.1.151
Mar 14 07:02:53 mythbackend mythbackend[30762]: E DBLogger mythdbcon.cpp:823 (pr
epare) Error preparing query: SELECT INFORMATION_SCHEMA.COLUMNS.COLUMN_NAME   FR
OM INFORMATION_SCHEMA.COLUMNS  WHERE INFORMATION_SCHEMA.COLUMNS.TABLE_SCHEMA =
      DATABASE()    AND INFORMATION_SCHEMA.COLUMNS.TABLE_NAME =        :TABLENAM
E    AND INFORMATION_SCHEMA.COLUMNS.COLUMN_NAME =        :COLUMNNAME;
Mar 14 07:02:53 mythbackend mythbackend[30762]: E DBLogger
mythdbcon.cpp:825 (prepare) Driver error was [2/1030]:#012QMYSQL3:
Unable to prepare statement#012Database error was:#012Got error 28
from storage engine
Mar 14 07:02:53 mythbackend mythbackend[30762]: E DBLogger
mythdbcon.cpp:823 (prepare) Error preparing query: SELECT
INFORMATION_SCHEMA.COLUMNS.COLUMN_NAME   FROM
INFORMATION_SCHEMA.COLUMNS  WHERE
INFORMATION_SCHEMA.COLUMNS.TABLE_SCHEMA =        DATABASE()    AND
INFORMATION_SCHEMA.COLUMNS.TABLE_NAME =        :TABLENAME    AND
INFORMATION_SCHEMA.COLUMNS.COLUMN_NAME =        :COLUMNNAME;
Mar 14 07:02:53 mythbackend mythbackend[30762]: E DBLogger
mythdbcon.cpp:825 (prepare) Driver error was [2/1030]:#012QMYSQL3:
Unable to prepare statement#012Database error was:#012Got error 28
from storage engine
Mar 14 07:02:53 mythbackend mythbackend[30762]: E DBLogger
mythdbcon.cpp:823 (prepare) Error preparing query: SELECT
INFORMATION_SCHEMA.COLUMNS.COLUMN_NAME   FROM
INFORMATION_SCHEMA.COLUMNS  WHERE
INFORMATION_SCHEMA.COLUMNS.TABLE_SCHEMA =        DATABASE()    AND
INFORMATION_SCHEMA.COLUMNS.TABLE_NAME =        :TABLENAME    AND
INFORMATION_SCHEMA.COLUMNS.COLUMN_NAME =        :COLUMNNAME;
Mar 14 07:02:53 mythbackend mythbackend[30762]: E DBLogger
mythdbcon.cpp:825 (prepare) Driver error was [2/1030]:#012QMYSQL3:
Unable to prepare statement#012Database error was:#012Got error 28
from storage engine
Mar 14 07:02:54 mythbackend mythbackend[30762]: E DBLogger
mythdbcon.cpp:823 (prepare) Error preparing query: SELECT
INFORMATION_SCHEMA.COLUMNS.COLUMN_NAME   FROM
INFORMATION_SCHEMA.COLUMNS  WHERE
INFORMATION_SCHEMA.COLUMNS.TABLE_SCHEMA =        DATABASE()    AND
INFORMATION_SCHEMA.COLUMNS.TABLE_NAME =        :TABLENAME    AND
INFORMATION_SCHEMA.COLUMNS.COLUMN_NAME =        :COLUMNNAME;

restarting mysql and relaunching causes this:

Mar 14 08:02:33 mythbackend mythbackend[31106]: E DBLogger
mythdbcon.cpp:825 (prepare) Driver error was [2/144]:#012QMYSQL3:
Unable to prepare statement#012Database error was:#012Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed

from mysql I get:
#144 - Table './mythconverg/logging' is marked as crashed and last
(automatic?) repair failed

it looks like mysql ran out of space on it's temp drive (it was a
tmpfs drive with 200MB, from a previous thread on the list regarding
speeding up mysql by doing this):
120313  6:49:11 [ERROR] /usr/sbin/mysqld: Disk is full writing '/tmp/mysql/STZBR
hpo' (Errcode: 28). Waiting for someone to free space... (Expect up to 60 secs d
elay for server to continue after freeing disk space)
120313  6:49:11 [ERROR] /usr/sbin/mysqld: Retry in 60 secs. Message
reprinted in 600 secs
120313  6:59:11 [ERROR] /usr/sbin/mysqld: Retry in 60 secs. Message
reprinted in 600 secs
120313  7:09:11 [ERROR] /usr/sbin/mysqld: Retry in 60 secs. Message
reprinted in 600 secs
120313  7:19:11 [ERROR] /usr/sbin/mysqld: Retry in 60 secs. Message
reprinted in 600 secs
120313  7:20:00 [Note] /usr/sbin/mysqld: Normal shutdown
120313  7:20:00 [Note] Event Scheduler: Purging the queue. 0 events
120313  7:20:02 [Warning] /usr/sbin/mysqld: Forcing close of thread
3548  user:'mythtv'
120313  7:20:11 [Note] Retrying repair of: './mythconverg/logging' with keycache
120313  7:20:12  InnoDB: Starting shutdown...
120313  7:20:14  InnoDB: Shutdown completed; log sequence number 0 1161217941
120313  7:20:14 [Note] /usr/sbin/mysqld: Shutdown complete
120313  7:20:53 [Note] Plugin 'FEDERATED' is disabled.
120313  7:20:53  InnoDB: Initializing buffer pool, size = 8.0M
120313  7:20:53  InnoDB: Completed initialization of buffer pool
120313  7:20:54  InnoDB: Started; log sequence number 0 1161217941
120313  7:20:54  InnoDB: Starting shutdown...
120313  7:20:59  InnoDB: Shutdown completed; log sequence number 0 1161217941
120313  7:20:59 [Note] Plugin 'FEDERATED' is disabled.
120313  7:20:59  InnoDB: Initializing buffer pool, size = 8.0M
120313  7:20:59  InnoDB: Completed initialization of buffer pool
120313  7:20:59  InnoDB: Started; log sequence number 0 1161217941
ERROR: 1064  You have an error in your SQL syntax; check the manual
that corresponds to your MySQL server version for the right syntax to
use near 'ALTER TABLE user ADD column Show_view_priv enum('N','Y')
CHARACTER SET utf8 NOT ' at line 1
120313  7:20:59 [ERROR] Aborting
120313  7:20:59  InnoDB: Starting shutdown...
120313  7:21:05  InnoDB: Shutdown completed; log sequence number 0 1161217941
120313  7:21:05 [Note] /usr/sbin/mysqld: Shutdown complete
120313  7:21:05 [Note] Plugin 'FEDERATED' is disabled.
120313  7:21:05  InnoDB: Initializing buffer pool, size = 8.0M
120313  7:21:05  InnoDB: Completed initialization of buffer pool
120313  7:21:05  InnoDB: Started; log sequence number 0 1161217941
120313  7:21:05  InnoDB: Starting shutdown...
120313  7:21:10  InnoDB: Shutdown completed; log sequence number 0 1161217941
120313  7:21:10 [Note] Plugin 'FEDERATED' is disabled.
120313  7:21:10  InnoDB: Initializing buffer pool, size = 8.0M
120313  7:21:10  InnoDB: Completed initialization of buffer pool
120313  7:21:10  InnoDB: Started; log sequence number 0
1161217941ERROR: 1050  Table 'plugin' already exists
120313  7:21:10 [ERROR] Aborting
120313  7:21:10  InnoDB: Starting shutdown...
120313  7:21:16  InnoDB: Shutdown completed; log sequence number 0 1161217941
120313  7:21:16 [Note] /usr/sbin/mysqld: Shutdown complete
120313  7:21:16 [Note] Plugin 'FEDERATED' is disabled.
120313  7:21:16  InnoDB: Initializing buffer pool, size = 8.0M
120313  7:21:16  InnoDB: Completed initialization of buffer pool
120313  7:21:16  InnoDB: Started; log sequence number 0 1161217941
120313  7:21:16 [Note] Event Scheduler: Loaded 0 events
120313  7:21:16 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.1.61-0ubuntu0.10.04.1'  socket:
'/var/run/mysqld/mysqld.sock'  port: 3306  (Ubuntu)
120313  7:21:16 [ERROR] /usr/sbin/mysqld: Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed
120313  7:21:16 [ERROR] /usr/sbin/mysqld: Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed
120313  7:21:16 [ERROR] /usr/sbin/mysqld: Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed
120313  7:21:16 [ERROR] /usr/sbin/mysqld: Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed
120313  7:21:16 [ERROR] /usr/sbin/mysqld: Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed
120313  7:21:16 [ERROR] /usr/sbin/mysqld: Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed
120313  7:21:16 [ERROR] /usr/sbin/mysqld: Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed
120313  7:21:16 [ERROR] /usr/sbin/mysqld: Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed
120313  7:21:16 [ERROR] /usr/sbin/mysqld: Table
'./mythconverg/logging' is marked as crashed and last (automatic?)
repair failed


I ran a 'repair table logging' in sql right now, but figured I'd throw
this out there as what could be a warning to others that 0.25 may need
more mysql tmpfs space than 0.24 did.

I'll report back when the repair table command finishes

-- 
Steve
http://www.mythtv.org/wiki/User:Steveadeff
Before you ask, read the FAQ!
http://www.mythtv.org/wiki/Frequently_Asked_Questions
then search the Wiki, and this list,
http://www.gossamer-threads.com/lists/mythtv/
Mailinglist etiquette - http://www.mythtv.org/wiki/Mailing_List_etiquette


More information about the mythtv-users mailing list