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

Paul Harrison mythtv at sky.com
Wed Mar 14 14:42:14 UTC 2012


On 14/03/12 14:19, Steven Adeff wrote:
> On Wed, Mar 14, 2012 at 8:21 AM, Steven Adeff <adeffs.mythtv at gmail.com> wrote:
>> 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
> command finished, status:ok. started mythbackend up and all looks to be good
>

Unless you really need it you can save yourself a lot of grief by
running everything with  --nodblog to disable the db logging.

Paul H.


More information about the mythtv-users mailing list