[mythtv-users] 0.25.0~master.20120314.c09b076 db crash error
Steven Adeff
adeffs.mythtv at gmail.com
Wed Mar 14 16:05:00 UTC 2012
On Wed, Mar 14, 2012 at 10:42 AM, Paul Harrison <mythtv at sky.com> wrote:
> 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.
yea, I thought of that in all this. I don't neeeed it, but it can be
nice. I'm interested at this point in why this happened, if it was
just running out of tmpfs space on the tmp drive I assigned to mysql,
or if for some other reason? and if db logging was the hair that broke
the camels back or if it would happen again without db logging enabled
as well.
--
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