:: #mythtv

Daily chat history

Current users (83):

aloril, amessina, Anssi, anykey__, autopatch, brfransen, CaCtus491, Captain_Murdoch, cattelan, clever, coling, Cougar, damaltor, danielk22, David_Mi1ler, dblain, dekarl1, dinamic|screen, dlblog, dmfrey, eharris_, ElmerFudd, foobum, foxbuntu, ghoti, gregL_, GreyFoxx, highzeth, idl0r, J-e-f-f-A, jams_, jarle, jcarlos, joe____, joki, jpabq, jwh, jwhite, knightr__, kurre2, kwmonroe, laga, mag0o, markcerv, MavT, mrec, MythBuild, MythLogBot, mzanetti, natanojl, peitolm, Peps, petefunk, pheld, poptix, purserj, rsiebert_, seld, Sharky112065, skd5aner, Slasher`, SmallR2002, sphery, sraue, stichnot_, stuarta, sutula, taylorr, tgm4883, ThisNewGuy, toeb, tomimo, tris, Unhelpful, vallor, Vernon_at_work, wagnerrp, wahrhaft, whoDat, xavierh, XDS2010, yb0t, _charly_
Sunday, June 17th, 2012, 00:00 UTC
[00:00:09] Beirdo: I'll try to reproduce it here though
[00:01:13] Seeker` (Seeker`!~cjo20@unaffiliated/seeker) has quit (Remote host closed the connection)
[00:23:56] sphery: stuartm: Does this work for you? (if you can confirm it does, I'll put it on the wiki)
[00:28:31] sphery: stuartm: better one:
[00:31:07] stichnot (stichnot!chatzilla@mythtv/developer/stichnot) has quit (Ping timeout: 252 seconds)
[00:51:29] robbiet480 (robbiet480! has joined #mythtv
[00:52:22] robbiet480 (robbiet480! has left #mythtv ()
[01:07:48] Seeker` (Seeker`!~cjo20@unaffiliated/seeker) has joined #mythtv
[01:09:28] danielk22: Beirdo: could be in a loop with no event handler. The segfault was in the UI thread during startup.
[01:12:25] gregL_ (gregL_! has quit (Read error: Connection reset by peer)
[01:14:02] danielk22: Beirdo: I don't think you can really assume the event loop is running when a SEGFAULT comes in...
[01:15:22] stichnot (stichnot!~chatzilla@ has joined #mythtv
[01:15:22] stichnot (stichnot!~chatzilla@mythtv/developer/stichnot) has joined #mythtv
[01:15:22] stichnot (stichnot!~chatzilla@ has quit (Changing host)
[01:21:24] sraue (sraue!~stephan@xbmc/staff/sraue) has quit (Quit: Ex-Chat)
[01:26:05] sraue (sraue!~stephan@xbmc/staff/sraue) has joined #mythtv
[01:28:11] gregL_ (gregL_! has joined #mythtv
[01:29:29] zombor (zombor!~zombor_@ has joined #mythtv
[01:29:29] zombor (zombor!~zombor_@ has quit (Changing host)
[01:29:29] zombor (zombor!~zombor_@kohana/developer/zombor) has joined #mythtv
[01:30:09] zombor (zombor!~zombor_@kohana/developer/zombor) has quit (Remote host closed the connection)
[01:32:05] zombor (zombor!~zombor_@ has joined #mythtv
[01:32:05] zombor (zombor!~zombor_@ has quit (Changing host)
[01:32:05] zombor (zombor!~zombor_@kohana/developer/zombor) has joined #mythtv
[01:34:03] zombor (zombor!~zombor_@kohana/developer/zombor) has quit (Remote host closed the connection)
[01:48:05] laga (laga! has quit (Ping timeout: 250 seconds)
[01:54:22] laga (laga! has joined #mythtv
[02:27:25] stichnot: OK buildbots, let me know if some platform doesn't define UINT64_MAX...
[02:28:32] jya (jya!~jyavenard@mythtv/developer/jya) has joined #mythtv
[02:44:45] jya (jya!~jyavenard@mythtv/developer/jya) has quit (Quit: jya)
[03:16:47] stichnot: wow, my frontend mythlogserver process seems to be consuming more than 500MB of memory
[03:37:11] danielk22: stichnot: my mythlogserver is using 1374 megabytes... there is definitely a big leak..
[03:40:07] danielk22: stichnot: on another machine the mythlogserver is using 1856 megabytes....
[03:40:21] danielk22: Beirdo: ^^^ mythlogserver is leaking
[03:41:18] jya (jya!~jyavenard@mythtv/developer/jya) has joined #mythtv
[03:43:24] laga (laga! has quit (Ping timeout: 246 seconds)
[03:50:26] laga (laga! has joined #mythtv
[04:07:32] stichnot: I'm running my frontends with "-v important,general,playback,vbi,libav --loglevel debug", so there is a lot of logging going on
[04:09:08] stichnot: That, plus the frontend machines having 2GB RAM and no swap, probably explains the recent frontend crashes I've been seeing
[04:15:46] stichnot: btw, I've been running with "--syslog local7". Now my log files are empty. Where are the logs going?
[04:24:04] danielk22: stichnot: I don't know, but it looks like --logpath doesn't work. It looks like there is only one mythlogserver and since it runs as the user of the first myth program to start it, it doesn't have permission to write the logs. i.e. if the backend runs as user mythtv, and I run a frontend as user mythtv-user then only the first to start gets to write it's log.
[04:25:07] danielk22: And sometimes a binary just refuses to run and just prints "Real-time signal 0" to the console.
[04:27:55] stichnot: danielk22: my --logpath seems to be working. (I use it in conjunction with --syslog local7)
[04:28:42] danielk22: stichnot: does the mythlogserver user have permission to write to all the --logpath directories?
[04:32:07] stichnot: danielk22: pretty sure it does
[04:32:22] stichnot: everything runs as the mythtv user
[04:32:46] danielk22: Then you wouldn't have any problems. Try running the frontend as the stichnot user..
[04:59:01] danielk22: stichnot: One frontend is using 1753 megabytes.. and hasn't been running very long..
[04:59:42] danielk22: stichnot: The backend on the same machine is using 1587 megabytes
[04:59:53] danielk22: Beirdo: ^^^
[05:15:15] danielk22: stichnot: Since both of us are seeing logging messages not make it to their destinations maybe these are backing up in the log server...
[05:15:46] stichnot: ah, that sounds plausible
[05:17:49] zombor (zombor!~zombor_@ has joined #mythtv
[05:17:50] zombor (zombor!~zombor_@ has quit (Changing host)
[05:17:50] zombor (zombor!~zombor_@kohana/developer/zombor) has joined #mythtv
[05:18:10] danielk22: yeah, if it were a reference counting issue I'm sure Beirdo would have seen it..
[05:26:34] danielk22: With -v all --loglevel debug I was able to get the frontend up above 2GB in less than a minute scrolling through Watch Recordings.. mythlogserver did not grow above 1800 meg though and fell back to 1400 meg after a minute or so. The frontend usage fell a little but is still above 2GB two minutes later.
[05:35:59] zombor (zombor!~zombor_@kohana/developer/zombor) has quit (Remote host closed the connection)
[05:56:37] jya (jya!~jyavenard@mythtv/developer/jya) has quit (Quit: jya)
[06:45:29] stoffel (stoffel! has joined #mythtv
[06:49:27] pheld (pheld! has joined #mythtv
[07:17:43] Beirdo: memory usage != leaks
[07:18:11] Beirdo: as we've told Udo many times... if you suspect leaks, please run valgrind (that's what I'll have to do anyways)
[07:18:55] Beirdo: and yeah, leaks are still a possibility, although not sure where at this point. Valgrind is our friend :)
[07:22:33] Beirdo: I'll take another good look at the logging items though, that was my suspicion earlier, but I thought I'd covered the eventuality. Likely missed something
[07:24:45] rsiebert_ (rsiebert_! has joined #mythtv
[07:25:38] rsiebert (rsiebert! has quit (Ping timeout: 246 seconds)
[07:25:50] map7_ (map7_! has joined #mythtv
[07:27:38] Beirdo: I will assume you guys ARE running near the tip of master, right?
[07:34:20] map7_ (map7_! has quit (Remote host closed the connection)
[07:56:01] Beirdo: I think I may have found part of the issue. If you are slamming the queue hard, it can start to fall behind due to the way I was pacing things.
[07:56:49] Beirdo: it would only handle 100 messages before going off to process events.
[07:58:21] Beirdo: I have a new methodology in there now that might work better. After a test compile, I'll submit it and we can try stressing that to see if it's better
[07:58:45] Beirdo: also, running with --nodblog may make a difference
[08:52:26] stoffel (stoffel! has quit (Ping timeout: 265 seconds)
[09:19:41] ** stuarta yawns **
[09:21:14] stuarta (stuarta! has quit (Changing host)
[09:21:14] stuarta (stuarta!~stuarta@mythtv/developer/stuarta) has joined #mythtv
[09:23:45] stuartm: Beirdo: mythlogserver isn't killed when exiting the backend, is that intentional?
[09:27:51] SteveGoodey (SteveGoodey! has joined #mythtv
[09:28:14] stuartm: sphery: that config doesn't work, I don't get any logs produced at all, I'll try and figure it out tonight
[09:29:00] toeb: sphery: I'm now using REG_JUMPEX but the callback is still called twice, if i press the assigned key in liveTV or playing a recording.
[09:29:53] stuartm (stuartm!~stuartm@mythtv/developer/stuartm) has quit (Remote host closed the connection)
[09:30:13] stuartm (stuartm!~stuartm@mythtv/developer/stuartm) has joined #mythtv
[10:29:09] natanojl (natanojl! has joined #mythtv
[10:53:35] Steve-Goodey (Steve-Goodey! has joined #mythtv
[11:00:13] Steve-Goodey (Steve-Goodey! has quit (Quit: Konversation terminated!)
[11:11:41] sphery: stuartm: mythlogserver should shut itself down when not used for some number of seconds (30s?)
[11:12:16] sphery: thanks for testing the config... If I get a chance to boot up the dev box, I'll see if I can do a better config. You used the "startswith" one, right (the 2nd one?)
[11:13:55] sphery: stichnot: if you're using --syslog, it will go to syslog, but all of our 0.25 configs for rsyslog need updating for mythlogserver's approach, so they won't properly filter--meaning your messages will likely end up in your main "everything" log (syslog.log or messages.log or ...)
[11:16:10] stuartm: sphery: ah ok, I might introduce a sleep into my init script, or have it kill the process otherwise changes in config or updates aren't honoured
[11:16:56] stuartm: took me a few minutes to figure out why my syslog config changes weren't having any effect
[11:17:08] sphery: stuartm: yeah, this is also probably something that mythtvd (the daemon runner program) could take care of (if only I'd get that written)
[12:24:37] jarle (jarle! has quit (Ping timeout: 265 seconds)
[12:33:41] jarle (jarle! has joined #mythtv
[12:44:13] stoffel (stoffel! has joined #mythtv
[12:46:14] jarle (jarle! has quit (Remote host closed the connection)
[12:49:11] jarle (jarle! has joined #mythtv
[12:55:40] cattelan (cattelan! has quit (Ping timeout: 244 seconds)
[13:01:55] kth (kth!~kth@unaffiliated/kth) has joined #mythtv
[13:06:02] kth (kth!~kth@unaffiliated/kth) has quit (Read error: Connection reset by peer)
[13:08:57] kth (kth!~kth@unaffiliated/kth) has joined #mythtv
[13:15:14] SteveGoodey (SteveGoodey! has quit (Quit: Konversation terminated!)
[13:32:03] danielk22: Beirdo: I don't think it's a memory leak in a strict sense, just excessive memory use.
[13:33:23] stoffel (stoffel! has quit (Ping timeout: 244 seconds)
[13:54:45] dmfrey: stuartm, thanks for the info, i will give it a shot
[14:15:18] dlblog (dlblog! has quit (Ping timeout: 265 seconds)
[14:21:08] dblain (dblain!~dblain@mythtv/developer/dblain) has joined #mythtv
[14:21:13] dlblog (dlblog! has joined #mythtv
[14:47:19] stichnot: sphery: it does look like my myth logs were going to some other syslog place.
[14:52:11] zombor (zombor!~zombor_@ has joined #mythtv
[14:52:12] zombor (zombor!~zombor_@ has quit (Changing host)
[14:52:12] zombor (zombor!~zombor_@kohana/developer/zombor) has joined #mythtv
[14:52:24] amessina (amessina!~amessina@2001:470:1f11:a4:d6be:d9ff:fe8d:7c1e) has joined #mythtv
[15:09:04] cattelan (cattelan! has joined #mythtv
[15:17:07] amessina (amessina!~amessina@2001:470:1f11:a4:d6be:d9ff:fe8d:7c1e) has quit (Quit: Konversation terminated!)
[15:18:14] zombor (zombor!~zombor_@kohana/developer/zombor) has quit (Remote host closed the connection)
[15:33:04] danielk22: Beirdo: I'm seeing a deadlock in the write() here signalhandling.cpp:120
[15:36:04] danielk22: The sigFd[0] value is 11.
[15:38:06] danielk22: write() can be interrupted by signals, but I have no idea how it behaves after a segfault..
[15:51:38] danielk22: Beirdo: I'm sure it's unrelated but write() can return without having written anything even inside a signal handler, we should check the return value and keep trying to write the value until it succeeds.
[15:56:43] andreax (andreax! has joined #mythtv
[16:10:45] zombor (zombor!~zombor_@ has joined #mythtv
[16:10:45] zombor (zombor!~zombor_@ has quit (Changing host)
[16:10:45] zombor (zombor!~zombor_@kohana/developer/zombor) has joined #mythtv
[16:13:37] danielk22: Beirdo: Reading up on this, you can not return from the segfault signal handler.. because the signal will be immediately reissued.... . . . loop-sigsegv
[16:14:05] danielk22: I'm guessing we're doing this repeatedly and eventually the write blocks..
[16:16:22] gregL_ (gregL_! has quit (Remote host closed the connection)
[16:18:36] gregL_ (gregL_! has joined #mythtv
[16:26:17] joki (joki! has quit (Ping timeout: 265 seconds)
[16:26:25] joki- (joki-! has joined #mythtv
[16:26:37] joki- is now known as joki
[16:42:33] danielk22: Beirdo: Here is sample code to deal with this:
[16:44:32] danielk22: Basically, we just wait in the signalHandler until we get a signal from SignalHandler::handleSignal() that it is time to issue the default action. Or if we never get that signal (because the fault happened in the thread the SignalHandler is running in) then we wait a little longer before issuing the default action.
[16:51:33] ChanServ (ChanServ!ChanServ@services.) has quit (*.net *.split)
[16:54:53] cattelan (cattelan! has quit (Ping timeout: 244 seconds)
[16:56:45] zombor (zombor!~zombor_@kohana/developer/zombor) has quit (Remote host closed the connection)
[17:06:45] cattelan (cattelan! has joined #mythtv
[17:27:13] stoffel (stoffel! has joined #mythtv
[17:28:40] dekarl1 (dekarl1! has joined #mythtv
[17:29:35] dekarl (dekarl! has quit (Ping timeout: 265 seconds)
[17:35:42] stoffel (stoffel! has quit (Ping timeout: 244 seconds)
[18:01:37] kth (kth!~kth@unaffiliated/kth) has quit (Quit: Leaving.)
[18:09:18] zombor (zombor!~zombor_@kohana/developer/zombor) has joined #mythtv
[19:01:09] NightMonkey (NightMonkey!~NightrMon@pdpc/supporter/professional/nightmonkey) has joined #mythtv
[19:21:17] amejia (amejia!~andres@ has joined #mythtv
[19:21:17] amejia (amejia!~andres@xbmc/staff/amejia) has joined #mythtv
[19:21:17] amejia (amejia!~andres@ has quit (Changing host)
[19:27:35] danielk22: stuartm: In mythpainter_yuva.cpp we call GetImageFromRect() a few times but we don't appear to use the image, any ideas what is going on there?
[19:56:35] Beirdo: danielk22: did you test that?
[19:57:08] Beirdo: we do never return from the handler I provided as I re-raise the signal with no handler right from the handler, so I'm not sure how this is any different, really
[19:57:41] Beirdo: oh, yes I do...
[19:57:49] Beirdo: but it's not going to do what we want
[19:58:13] Beirdo: I think
[19:58:39] Beirdo: the whole idea is to delay to allow the other threads (in particular the logging thread) to finish what they were doing.
[19:59:01] Beirdo: if you delay right in the unix signal handler, I don't think that will work quite right
[19:59:46] Beirdo: and segfaults work fine for me
[20:00:03] Beirdo: I just intentionally segfaulted my frontend
[20:00:47] danielk22: Beirdo: I tested it. Put this in a method that gets called in the UI thread { QString str; memset(&str, 0, sizeof(str)); LOG(VB_GENERAL, LOG_INFO, QString("%1").arg(str)); }
[20:01:21] danielk22: The current code will work if you just send a SEGFAULT signal via kill, but it won't work if a real segfault occurs in the UI thread.
[20:01:33] Beirdo: hmmm
[20:01:34] Beirdo: OK
[20:01:35] danielk22: The link above explains why.
[20:02:08] Beirdo: it explains it via an uncited opinion :)
[20:02:21] Beirdo: I'm looking for what POSIX says, haven't found it yet
[20:03:07] danielk22: A real segfault or similar signal will get resent forever because we resume execution and then whatever caused the signal to be raised is re-raised... and then we will never progress in the code to the point where the handler is run.
[20:03:07] Beirdo: it does seem a reasonable way to fix it though
[20:03:20] Beirdo: oh crap
[20:03:32] Beirdo: hahah, you are right. Never mind. :)
[20:03:34] Beirdo: duh
[20:03:52] Beirdo: how many processors on your box?
[20:03:54] danielk22: Beirdo: Well I assume you will prettify it.. it's just illustrating one way to fix. ;]
[20:03:56] Beirdo: err cores?
[20:04:11] danielk22: Beirdo: This is on my laptop which has two cores.
[20:04:27] Beirdo: that may also be part of the difference as another core could run the handler, potentially
[20:04:49] Beirdo: ahh, I'm on a dual core for the frontend, i7 quad core on the backend
[20:04:53] Beirdo: so likely not that
[20:05:07] Beirdo: but yeah. OK, very good catch.
[20:05:10] Beirdo: hmm
[20:05:23] danielk22: No, it can't.. the Qt notifier is only run when the events in the thread that it was created in are processed..
[20:05:25] Beirdo: well, I guess since all we do is delay, that SHOULD be benign
[20:05:49] danielk22: It won't run when you run the even processing for a different thread.
[20:05:56] danielk22: s/even/event/
[20:06:13] Beirdo: hmm
[20:06:18] Beirdo: gotcha
[20:06:55] Beirdo: OK, this will be fixed momentarily :)
[20:07:04] danielk22: Another way this could be handled would be to dedicate a thread to the notifier object. Then that thread would always be running and presumably would never fault itself.
[20:07:44] danielk22: But since we're using the UI thread which does a lot of other things that could cause segfaults..
[20:08:03] Beirdo: yeah
[20:08:18] Beirdo: I had considered that, but backed out of it for some reason I forget
[20:08:57] Beirdo: that does sound cleaner though, doesn't it?
[20:09:01] danielk22: Beirdo: I created tickets for the three different issues with signals. I only created a PoC for this particular one since it was making it difficult to debug the reference counting...
[20:09:38] Goga777 (Goga777!~Goga777@ has joined #mythtv
[20:09:38] Goga777 (Goga777!~Goga777@ has quit (Client Quit)
[20:09:47] Beirdo: perfect :) I got me some work to do. Thanks for the tickets, it makes it easier to not forget details
[20:10:49] danielk22: Sure. Up to you on the details, there is a tradeoff of course in that it's yet another thread in our backtraces..
[20:11:15] Beirdo: yeah, exactly. That may have been why I didn't do it.
[20:12:00] Beirdo: I think you might as well just commit that patch. Looks good to me. I might consider doing a separate thread still though, but at least it will fix the issue for now.
[20:12:37] Beirdo: did my change from last night have any effect on your logging under high log load, BTW?
[20:13:34] Beirdo: oh, and you might want to add SIGABRT to use the same logic there from SIGSEGV handling
[20:13:45] danielk22: Beirdo: I'm going to be away from the computer the next couple hours, but I can commit this later today. I haven't synced with the changes from last night yet so don't know on that.
[20:13:48] Beirdo: as the code really is pretty much the same, even if it's not required
[20:14:00] Beirdo: Ah OK, no problem
[20:14:16] Beirdo: it's a beautiful day here, I think I might spend a bit of time outside even
[20:14:23] Beirdo: have a wonderful Father's Day :)
[20:14:38] danielk22: heh, same weather here :) Thanks
[20:47:41] stuartm: danielk22: it seems GetImageFromRect() caches the image using a hash based on the area/brush etc, if we call GetImageFromRect() a second time with the same args it returns a pointer to the existing copy in the cache, so it's setting the format to YUV so that MythPainter::DrawRect() or whatever returns the correct image format
[20:50:08] stuartm: note that it goes on to call MythQImagePainter::DrawRect() which calls MythPainter::DrawRect() which ultimately returns a pointer to that same cached image
[20:50:37] stuartm: err, not returns, it calls DrawImage() to draw it
[20:52:32] stuartm: the cache expires the image when we reach the cache max size (MythPainter::m_MaxSoftwareCacheSize) (see MythPainter::GetImageFromRect() for full detail of the cache behaviour)
[20:54:08] stuartm: this is a second image cache, which seems to be independent of the 'main' image cache, reserved for string/shape textures ...
[21:01:35] stuartm: gigem, danielk22: that backend deadlock involves the scheduler, although it may not be the cause –
[21:02:36] stuartm: it's deadlocked as a recording was starting, we're calling EITScanner::StopActiveScan() which iirc was in the neighbourhood of danielk22's recent deadlock fixes
[21:04:42] gigem (gigem!~david@mythtv/developer/gigem) has quit (Quit: WeeChat 0.3.7)
[21:06:01] gigem (gigem! has joined #mythtv
[21:06:01] gigem (gigem!~david@mythtv/developer/gigem) has joined #mythtv
[21:06:01] gigem (gigem! has quit (Changing host)
[21:06:27] amessina (amessina!~amessina@2001:470:1f11:a4:d6be:d9ff:fe8d:7c1e) has joined #mythtv
[21:15:08] stuartm: [e148984]
[21:29:13] jstenback (jstenback!~jstenback@2620:101:8003:200:224:e8ff:fe39:34c2) has quit (Ping timeout: 245 seconds)
[21:46:55] jya (jya!~jyavenard@mythtv/developer/jya) has joined #mythtv
[21:47:07] stuartm: ok, I can't quite piece together the full picture but it seems that if the EIT scanner requests a reschedule immediately before we start recording the recorder thread, eit thread and main thread (scheduler et al) become deadlocked but it doesn't involve one single lock
[21:50:00] stuartm: it might be the lock of the main thread and event loop which is ultimately the problem, that's waiting for the scheduler lock to be released by Scheduler::HandleRecording in the recorder thread, the recorder thread is waiting for an event or something to be processed in the main event loop?
[22:30:06] jya (jya!~jyavenard@mythtv/developer/jya) has quit (Quit: jya)
[22:57:36] NightMonkey (NightMonkey!~NightrMon@pdpc/supporter/professional/nightmonkey) has quit (Remote host closed the connection)
[23:13:16] andreax (andreax! has quit (Read error: Connection reset by peer)
[23:23:01] aloril (aloril! has quit (Ping timeout: 260 seconds)
[23:28:43] Chutt (Chutt! has quit (Ping timeout: 265 seconds)
[23:32:07] aloril (aloril! has joined #mythtv

IRC Logs collected by BeirdoBot.
Please use the above link to report any bugs.