Opened 10 years ago
Closed 10 years ago
#12411 closed Bug Report - Hang/Deadlock (Invalid)
threadedfilewriter - 'Maximum buffer size exceeded' & 'Taking to long to flush..'
| Reported by: | Owned by: | JYA | |
|---|---|---|---|
| Priority: | minor | Milestone: | unknown |
| Component: | MythTV - Recording | Version: | 0.27.4 |
| Severity: | medium | Keywords: | |
| Cc: | Ticket locked: | yes |
Description
Getting this error consistently a couple time a week.
After the first Maximum buffer size exceeded error, the backend continues to think its recording.
When the recording completes, the Taking to long to flush error locks future recordings and playbacks.
My system is similar to this thread:
http://lists.mythtv.org/pipermail/mythtv-users/2014-November/373972.html
Raid 0, 7200 HDs HDHR-US 20150127beta1
Not sure is the initial error can eliminated, but I am hoping the then second error can be detected and unlock threadedfilewriter hang.
[root@mythtvquad ~]# mythbackend --version Please attach all output as a file in bug reports. MythTV Version : v0.27.4-34-gca4a2d6 MythTV Branch : fixes/0.27 Network Protocol : 77 Library API : 0.27.20141016-1 QT Version : 4.8.6 Options compiled in:
linux profile use_hidesyms using_alsa using_oss using_backend using_bindings_perl using_bindings_python using_bindings_php u
sing_crystalhd using_dvb using_firewire using_frontend using_hdhomerun using_ceton using_hdpvr using_ivtv using_joystick_menu
using_libcrypto using_libdns_sd using_libfftw3 using_libxml2 using_libudf using_lirc using_mheg using_opengl using_opengl_vi
deo using_qtwebkit using_qtscript using_qtdbus using_taglib using_v4l2 using_x11 using_xrandr using_xv using_profiletype usin g_bindings_perl using_bindings_python using_bindings_php using_mythtranscode using_opengl using_vaapi using_vdpau using_ffmpe g_threads using_mheg using_libass using_libxml2 using_libudf
Log:
2015-03-12T14:59:00.009364-05:00 mythbackend[2230]: N Scheduler scheduler.cpp:2772 (HandleIdleShutdown?) Blocking shutdown because a recording is due to start soon. 2015-03-12T14:59:15.019412-05:00 mythbackend[2230]: N Scheduler scheduler.cpp:2772 (HandleIdleShutdown?) Blocking shutdown because a recording is due to start soon. 2015-03-12T14:59:25.025967-05:00 mythbackend[2230]: N Scheduler scheduler.cpp:2772 (HandleIdleShutdown?) Blocking shutdown because a recording is due to start soon. 2015-03-12T14:59:30.029591-05:00 mythbackend[2230]: I Scheduler mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 15 2015-03-12T14:59:30.030255-05:00 mythbackend[2230]: N Scheduler scheduler.cpp:2772 (HandleIdleShutdown?) Blocking shutdown because a recording is due to start soon. 2015-03-12T14:59:30.530337-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[6]: ASK_RECORDING 6 29 0 0 2015-03-12T14:59:30.630582-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[8]: ASK_RECORDING 8 28 0 0 2015-03-12T14:59:30.730858-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[5]: ASK_RECORDING 5 29 0 0 2015-03-12T14:59:30.731514-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:1567 (HandlePendingRecordings?) TVRec[7]: ASK_RECORDING 7 28 0 0 2015-03-12T14:59:45.040435-05:00 mythbackend[2230]: N Scheduler scheduler.cpp:2772 (HandleIdleShutdown?) Blocking shutdown because a recording is due to start soon. 2015-03-12T15:00:00.151028-05:00 mythbackend[2230]: I CoreContext? mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 15 2015-03-12T15:00:00.151354-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[5]: Changing from None to RecordingOnly? 2015-03-12T15:00:00.155378-05:00 mythbackend[2230]: I TVRecEvent mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 15 2015-03-12T15:00:00.155400-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:3603 (TuningCheckForHWChange) TVRec[5]: HW Tuner: 5->5 2015-03-12T15:00:00.155405-05:00 mythbackend[2230]: N Scheduler autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 14 min 2015-03-12T15:00:00.155425-05:00 mythbackend[2230]: I Scheduler scheduler.cpp:2690 (HandleRecordingStatusChange?) Tuning recording: "Dr. Phil":"Is Mom Leading a Secret Life, or Are These Daughters Caught Up in Drama?": channel 4642 on cardid 5, sourceid 4 2015-03-12T15:00:00.155430-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[7]: Changing from None to RecordingOnly? 2015-03-12T15:00:00.155435-05:00 mythbackend[2230]: I TVRecEvent mythdbcon.cpp:409 (PurgeIdleConnections?) New DB connection, total: 15 2015-03-12T15:00:00.155521-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:3603 (TuningCheckForHWChange) TVRec[7]: HW Tuner: 7->7 2015-03-12T15:00:00.252502-05:00 mythbackend[2230]: N Scheduler autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min 2015-03-12T15:00:00.253184-05:00 mythbackend[2230]: I Scheduler scheduler.cpp:2690 (HandleRecordingStatusChange?) Tuning recording: "The Ellen DeGeneres? Show": channel 14283 on cardid 7, sourceid 4 2015-03-12T15:00:00.253845-05:00 mythbackend[2230]: I Scheduler scheduler.cpp:2140 (HandleReschedule?) Reschedule requested for PLACE PrepareToRecord? 2015-03-12T15:00:00.254500-05:00 mythbackend[2230]: I Scheduler scheduler.cpp:2140 (HandleReschedule?) Reschedule requested for PLACE PrepareToRecord? 2015-03-12T15:00:00.453420-05:00 mythbackend[2230]: I Scheduler scheduler.cpp:2253 (HandleReschedule?) Scheduled 394 items in 0.2 = 0.00 match + 0.00 check + 0.25 place 2015-03-12T15:00:00.753898-05:00 mythbackend[2230]: I CoreContext? scheduler.cpp:705 (UpdateRecStatus?) Updating status for "Dr. Phil":"Is Mom Leading a Secret Life, or Are These Daughters Caught Up in Drama?" on cardid 5 (Tuning => Recording) 2015-03-12T15:00:00.854225-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:4130 (TuningNewRecorder?) TVRec[5]: rec->GetPathname?(): '/data/storage/raid/mythraid/tv/4642_20150312200000.mpg' 2015-03-12T15:00:00.855134-05:00 mythbackend[2230]: E TVRecEvent recorders/recorderbase.cpp:206 (SetStrOption?) RecBase?[5](101966A6-1): SetStrOption?(...recordingtype): Option not in profile. 2015-03-12T15:00:00.855840-05:00 mythbackend[2230]: I CoreContext? scheduler.cpp:705 (UpdateRecStatus?) Updating status for "The Ellen DeGeneres? Show" on cardid 7 (Tuning => Recording) 2015-03-12T15:00:00.856515-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:4130 (TuningNewRecorder?) TVRec[7]: rec->GetPathname?(): '/data/storage/raid/mythraid/tv/14283_20150312200000.mpg' 2015-03-12T15:00:00.857190-05:00 mythbackend[2230]: E TVRecEvent recorders/recorderbase.cpp:206 (SetStrOption?) RecBase?[7](101966A6-0): SetStrOption?(...recordingtype): Option not in profile. 2015-03-12T15:00:29.475555-05:00 mythbackend[2230]: I Metadata_2713 jobqueue.cpp:2156 (DoMetadataLookupThread?) JobQueue?: Metadata Lookup Starting for "Dr. Phil":"Is Mom Leading a Secret Life, or Are These Daughters Caught Up in Drama?" recorded from channel 4642 at 2015-03-12T20:00:00Z 2015-03-12T15:00:30.677042-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Playback 2015-03-12T15:00:30.677626-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:00:30.678202-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:00:30.678801-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 1) 2015-03-12T15:00:34.480399-05:00 mythbackend[2230]: I Metadata_2715 jobqueue.cpp:2156 (DoMetadataLookupThread?) JobQueue?: Metadata Lookup Starting for "The Ellen DeGeneres? Show" recorded from channel 14283 at 2015-03-12T20:00:00Z 2015-03-12T15:00:35.682205-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Playback 2015-03-12T15:00:35.682946-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:00:35.683561-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:00:35.684150-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 1) 2015-03-12T15:00:39.486792-05:00 mythbackend[2230]: I Commflag_2714 jobqueue.cpp:2281 (DoFlagCommercialsThread?) JobQueue?: Commercial Detection Starting for "Dr. Phil":"Is Mom Leading a Secret Life, or Are These Daughters Caught Up in Drama?" recorded from channel 4642 at 2015-03-12T20:00:00Z 2015-03-12T15:00:39.787114-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Playback 2015-03-12T15:00:39.787593-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:00:39.788027-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:00:39.788467-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 1) 2015-03-12T15:00:39.888446-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Playback 2015-03-12T15:00:39.888924-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:00:44.492928-05:00 mythbackend[2230]: I Commflag_2716 jobqueue.cpp:2281 (DoFlagCommercialsThread?) JobQueue?: Commercial Detection Starting for "The Ellen DeGeneres? Show" recorded from channel 14283 at 2015-03-12T20:00:00Z 2015-03-12T15:00:44.793345-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Playback 2015-03-12T15:00:44.793813-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:00:44.794265-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:00:44.794721-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 1) 2015-03-12T15:00:44.894444-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Playback 2015-03-12T15:00:44.895123-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:03:07.999453-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:03:07.999894-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:03:08.000333-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:03:08.001305-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:03:08.100057-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:03:08.100729-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:04:02.241994-05:00 mythbackend[2230]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min 2015-03-12T15:08:08.626698-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:08:08.626720-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:08:08.626725-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:08:08.626729-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:12:02.211682-05:00 mythbackend[2230]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min 2015-03-12T15:13:10.473019-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:13:10.473040-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:13:10.473045-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:13:10.473048-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:18:12.550458-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:18:12.550975-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:18:12.551444-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:18:12.551962-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:19:02.199147-05:00 mythbackend[2230]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min 2015-03-12T15:23:11.904641-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:23:11.905480-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:23:11.906115-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:23:11.906776-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:27:02.205567-05:00 mythbackend[2230]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min 2015-03-12T15:27:11.612174-05:00 mythbackend[2230]: E HDHRStreamHandler threadedfilewriter.cpp:239 (Write) TFW(/data/storage/raid/mythraid/tv/14283_20150312200000.mpg:88): Maximum buffer size exceeded.#012#011#011#011file will be truncated, no further writing will be done.#012#011#011#011This generally indicates your disk performance #012#011#011#011is insufficient to deal with the number of on-going #012#011#011#011recordings, or you have a disk failure. 2015-03-12T15:28:13.754318-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:28:13.754997-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:28:13.755565-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:28:13.756027-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:29:08.394050-05:00 mythbackend[2230]: E HDHRStreamHandler threadedfilewriter.cpp:239 (Write) TFW(/data/storage/raid/mythraid/tv/4642_20150312200000.mpg:80): Maximum buffer size exceeded.#012#011#011#011file will be truncated, no further writing will be done.#012#011#011#011This generally indicates your disk performance #012#011#011#011is insufficient to deal with the number of on-going #012#011#011#011recordings, or you have a disk failure. 2015-03-12T15:33:13.557664-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:33:13.557697-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:33:13.557702-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:33:13.557707-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:34:02.190548-05:00 mythbackend[2230]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min 2015-03-12T15:38:14.157159-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:38:14.157181-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:38:14.157185-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:38:14.157189-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:41:02.274610-05:00 mythbackend[2230]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min 2015-03-12T15:43:14.662868-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:43:14.662892-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:43:14.763010-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:43:14.763677-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:48:02.253395-05:00 mythbackend[2230]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min 2015-03-12T15:48:15.262790-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:48:15.262821-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:48:15.362787-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:48:15.363460-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:53:15.762366-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:53:15.762387-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:53:15.862384-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:53:15.862999-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:55:02.236006-05:00 mythbackend[2230]: N Expire autoexpire.cpp:264 (CalcParams?) AutoExpire?: CalcParams?(): Max required Free Space: 3.0 GB w/freq: 7 min 2015-03-12T15:58:16.365457-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:58:16.365855-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:58:16.366327-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:58:16.366800-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:58:16.367263-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:58:16.367732-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T15:58:16.466654-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1446 (HandleAnnounce?) MainServer::ANN Monitor 2015-03-12T15:58:16.467341-05:00 mythbackend[2230]: I ProcessRequest? mainserver.cpp:1448 (HandleAnnounce?) adding: mythtvquad as a client (events: 0) 2015-03-12T16:00:00.617097-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[7]: Changing from RecordingOnly? to None 2015-03-12T16:00:00.917751-05:00 mythbackend[2230]: I TVRecEvent tv_rec.cpp:1050 (HandleStateChange?) TVRec[5]: Changing from RecordingOnly? to None 2015-03-12T16:00:02.719448-05:00 mythbackend[2230]: W RecThread? threadedfilewriter.cpp:351 (Flush) TFW(/data/storage/raid/mythraid/tv/14283_20150312200000.mpg:88): Taking a long time to flush.. buffer size 67033844 2015-03-12T16:00:03.019869-05:00 mythbackend[2230]: W RecThread? threadedfilewriter.cpp:351 (Flush) TFW(/data/storage/raid/mythraid/tv/4642_20150312200000.mpg:80): Taking a long time to flush.. buffer size 67104908 2015-03-12T16:00:04.621361-05:00 mythbackend[2230]: W RecThread? threadedfilewriter.cpp:351 (Flush) TFW(/data/storage/raid/mythraid/tv/14283_20150312200000.mpg:88): Taking a long time to flush.. buffer size 67033844
Change History (7)
comment:1 Changed 10 years ago by
comment:2 Changed 10 years ago by
| Resolution: | → Invalid |
|---|---|
| Status: | new → closed |
The errors mean just that. Your system is too slow at writing and myth can't get around it any longer.
There's nothingg wrong with the code, it does what it's supposed to do.
comment:3 follow-up: 4 Changed 10 years ago by
I can understand the blaming first error on the speed of the system. However most of the time i can record three HD shows and while watching another HD show all at the same time. I think the issue is a combination of recording two show, having both show starting commercial detection and meta gathering while they are still recording. From the threads mentioned, there is a patch that seems to corrects this issue.
The second error is that the backend hanging; this should be preventable. The code detected the buffering issue threw and error and gave up. However the program did not attempt to close the thread and then restart the recording. In fact the code kept thinking it was recording. Then when the show ended, but the thread gets stuff in an endless loop waiting for the recording to save. But the code at knows its not going to save because it gave up. MythTv? is then down until dead lock is manually detected.
This issue has just appeared for me after upgrading the to latest version of the software. The box has been running the latest release knoppixMyth/LinHes for almost the last decade with out issue.
The raid is running XFS the file system.
comment:4 Changed 10 years ago by
Replying to thekingofspain@…:
From the threads mentioned, there is a patch that seems to corrects this issue.
One part of the patch disables fsync/fdatasync functionality. That may fix one symptom for some, while at the same time reintroduce the other symptoms that adding fsync/fdatasync solved for others, as the author of the patch warned. You can go back in the history to understand why the fsync was added, and why it is (on average) goodness. Unless you can show facts why all of that information is now completely wrong, you are unlikely to sway anyone into thinking that reverting to the old problems is a good way forward.
Certain file system types seem to be more problematic than others. If you are willing to accept higher risks, disabling barriers on XFS might work for you. Or not.
It is possible that a first approach (that might be acceptable to the devs) would be a clean patch that allowed someone to configure their particular system via an appropriate mythtv-setup setting page to choose whether to disable fsync for those with special needs as long as the default stayed the same. I suspect the hardest part is likely the mythtv-setup (and upcoming web) configuration piece, with all the warnings about how you may be breaking functionality, and do you really, really want to make this change. Perhaps the more complete approach would require a complete rethinking and re-factoring of all the code to accommodate all systems and file-systems in some sort of dynamic fashion, trying, desperately, to handle systems that are fundamentally under-resourced.
Of course, no one is preventing you from building your own programs with the patches you find useful to yourself, and accepting any of the fallout that goes with it.
comment:5 Changed 10 years ago by
Still getting lockups at certain times, so nothing is popping out from the logs or stats. Switched the scheduler to deadline since it benchmarked the fastest of the three schedulers on the machine. Drives are SATA 7200 RPM.
Runnning a test now, watching a recording, and recording 3 shows:
iostat -x 1
vg-cpu: %user %nice %system %iowait %steal %idle
1.77 5.30 1.52 2.53 0.00 88.89
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 sdb 0.00 0.00 0.00 11.00 0.00 2386.00 433.82 0.16 14.55 0.00 14.55 13.64 15.00 sdc 0.00 0.00 2.00 11.00 512.00 2386.00 445.85 0.47 36.46 32.00 37.27 15.85 20.60 scd0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 md0 0.00 0.00 2.00 9.00 512.00 2384.00 526.55 0.00 0.00 0.00 0.00 0.00 0.00
That was the highest utilization that was reported.
comment:6 Changed 10 years ago by
| Resolution: | Invalid |
|---|---|
| Status: | closed → new |
For what its worth, since changing the scheduler to deadline this issue has not reoccurred. The existing hardware is the same, and the issue started after an upgrade to LinHes?:
To: 19-Feb-2015 R8.3 Lorne Malvo MythTV 0.27-fixes (0.27.4) (Changelog) From: 27-Oct-2014 R8.2 Paid the iron price MythTV 0.27-fixes (0.27.4) (Changelog)
http://www.linhes.org/projects/linhes/wiki/History
Not seeing anything in the change logs that point to an update to mythtv or archlinux version was bumped.
comment:7 Changed 10 years ago by
| Resolution: | → Invalid |
|---|---|
| Status: | new → closed |
| Ticket locked: | set |
Also see
http://www.mythtvtalk.com/strange-error-occuring-recordings-being-truncated-16252/
Besides the raid theme, the hdhr is recording HD content that cable provider is rebroadcasting on a SD channel.
Replying to thekingofspain@…: