| Thursday, June 2nd, 2011, 00:00 UTC | ||
| [00:00:34] | markk: | GreyFoxx: base address is coming up as an ipv6 address to start... hence the fix isn't helping |
| [00:01:31] | GreyFoxx: | where are you seeing that ? |
| [00:01:43] | GreyFoxx: | got a log bit or something I can look at? |
| [00:01:58] | GreyFoxx: | and I should ask |
| [00:02:17] | GreyFoxx: | are you using IPv6 addressing in your mythconfig or ipv4 ? |
| [00:06:49] | markk: | GreyFoxx: the logging coming out of SSDPExtension::GetDeviceDesc shows an ipv6 address which is passed to GetValidXML. ipv4 in my setup. |
| [00:06:56] | GreyFoxx: | k |
| [00:07:05] | GreyFoxx: | I'm looking at that now |
| [00:11:46] | abqjp (abqjp!~abqjp@174-28-187-116.albq.qwest.net) has joined #mythtv | |
| [00:21:10] | markk: | taylorr: so are still hitting some sort of issue on the backend side? |
| [00:28:38] | ThisNewGuy1 (ThisNewGuy1!~doug@pool-98-109-19-98.nwrknj.fios.verizon.net) has joined #mythtv | |
| [00:30:46] | ThisNewGuy (ThisNewGuy!~doug@pool-98-109-19-98.nwrknj.fios.verizon.net) has quit (Read error: Connection reset by peer) | |
| [00:31:10] | coling (coling!~colin@cpc1-sgyl30-2-0-cust258.sgyl.cable.virginmedia.com) has quit (Ping timeout: 246 seconds) | |
| [00:31:15] | coling (coling!~colin@cpc1-sgyl30-2-0-cust258.sgyl.cable.virginmedia.com) has joined #mythtv | |
| [00:31:20] | kwmonroe (kwmonroe!~kwmonroe@32.97.110.58) has quit (Ping timeout: 240 seconds) | |
| [00:31:38] | kwmonroe (kwmonroe!~kwmonroe@32.97.110.58) has joined #mythtv | |
| [00:32:11] | kc (kc!~Casper@unaffiliated/kc) has quit (Ping timeout: 240 seconds) | |
| [00:32:56] | kc (kc!~Casper@unaffiliated/kc) has joined #mythtv | |
| [00:38:33] | PointyPumper (PointyPumper!~pintlezz@190.244.73.13) has quit () | |
| [00:39:54] | kormoc is now known as kormoc_afk | |
| [00:44:03] | sphery: | taylorr: I think Beirdo is planning to redo the testing you did earlier with the branch, but now that he pushed the schema update for new-logging into master, it's easy to switch back and forth. So, if you're interested, you could git checkout new-logging and play with it to see if it "fixes" (or avoids) the vdpau pause problem (we know it doesn't avoid the event processing pause, but might help the other) |
| [00:44:43] | wahrhaft (wahrhaft!~quassel@cpe-24-210-71-26.columbus.res.rr.com) has quit (Remote host closed the connection) | |
| [00:45:12] | gigem (gigem!~david@mythtv/developer/gigem) has quit (Remote host closed the connection) | |
| [00:45:37] | gigem (gigem!~david@mythtv/developer/gigem) has joined #mythtv | |
| [00:46:06] | wahrhaft (wahrhaft!~quassel@cpe-24-210-71-26.columbus.res.rr.com) has joined #mythtv | |
| [00:46:07] | MaverickTech (MaverickTech!~MaverickT@111.86.233.220.static.exetel.com.au) has quit (Read error: Connection reset by peer) | |
| [00:46:27] | MaverickTech (MaverickTech!~MaverickT@111.86.233.220.static.exetel.com.au) has joined #mythtv | |
| [00:49:39] | GreyFoxx: | mark: Care to try: http://pastebin.ca/2073466 |
| [00:49:54] | GreyFoxx: | it's all of the previous in one as well |
| [01:08:36] | mrand (mrand!~mrand@ubuntu/member/mrand) has left #mythtv () | |
| [01:14:43] | danielk22 (danielk22!~danielk@96.57.9.142) has joined #mythtv | |
| [01:14:49] | danielk22 (danielk22!~danielk@96.57.9.142) has left #mythtv () | |
| [01:19:42] | taylorr: | sphery: thanks for the offer but I'm doing all my testing on 0.24-fixes :) |
| [01:20:21] | mrand (mrand!~mrand@ubuntu/member/mrand) has joined #mythtv | |
| [01:20:59] | taylorr: | markk: yes, the backend is definitely the culprit.... with help from Beirdo and kormoc we've got straces of the threads doing the RequestBlock() in filetransfer.cpp |
| [01:22:04] | taylorr: | they show a tons of mutex waits (>10ms each) that seem to be triggered by VERBOSE and lock/unlock against unused locks |
| [01:23:23] | markk: | GreyFoxx: all looking good:) thanks – (btw – I think there is a stray else in the upnpdevice code) |
| [01:23:45] | taylorr: | Beirdo: here is the patch -> http://mythtv.pastebin.ca/2073479 |
| [01:24:04] | Beirdo: | thanks :) |
| [01:24:11] | taylorr: | I'd like to have it should the TIDs just one time and not everytime the thread gets called |
| [01:24:32] | taylorr: | can eliminate even more VERBOSE and syscalls |
| [01:24:43] | taylorr: | s/should/show/ |
| [01:25:06] | Beirdo: | yeah |
| [01:26:18] | taylorr: | Beirdo: it'd actually be useful if we had that kinda debug checked into the codebase for situations like these so we can attach gdb and strace to correct TID |
| [01:26:42] | fmilo (fmilo!~fmilo@64.17.253.218) has joined #mythtv | |
| [01:26:59] | Beirdo: | yeah, I may add that in the new logging in the debugging part |
| [01:27:04] | fmilo (fmilo!~fmilo@64.17.253.218) has quit (Read error: Connection reset by peer) | |
| [01:27:39] | taylorr: | markk: there are two mysteries that need to be solved 1) why do lock/unlock against free locks take so long (MUTEX waits) and 2) why does VERBOSE also trigger them |
| [01:27:57] | Beirdo: | gdb isn't an issue though, you can attach to the main pid and switch threads |
| [01:28:26] | taylorr: | I've noticed for a while that if you turn on many verbose flags the backend slows down considerably |
| [01:30:51] | taylorr: | markk: here is an strace of RequestBlock() which shows the FUTEX_WAITS -> http://mythtv.pastebin.ca/2073430 |
| [01:32:33] | taylorr: | markk: in that log check out starting at line 23 (gettid() call) – the lines that follow appear to be caused by a VERBOSE call |
| [01:33:02] | taylorr: | there are 3 FUTEX_WAIT calls that total more than 32 msec |
| [01:33:15] | taylorr: | so a single VERBOSE causes a 30 msec delay |
| [01:34:24] | Beirdo: | I'll have an strace up from new-logging in a moment |
| [01:37:31] | Beirdo: | http://mythtv.pastebin.ca/2073482 |
| [01:38:54] | Beirdo: | the really long (1s or so) relative timings is where it's gone to the thread pool and grabbed this thread again |
| [01:43:07] | taylorr: | Beirdo: you have the FUTEX_WAITs where the VERBOSE call is but they are very fast |
| [01:43:17] | taylorr: | nothing even close to the 11 msec ones in my strace |
| [01:44:30] | taylorr: | Beirdo: maybe you should get an strace from the master branch for comparison's sake |
| [01:45:28] | Beirdo: | will do |
| [01:45:44] | taylorr: | maybe this problem is only on 0.24-fixes |
| [01:45:46] | jya (jya!~jyavenard@mythtv/developer/jya) has joined #mythtv | |
| [01:45:49] | taylorr: | or just my machine :) |
| [01:47:26] | taylorr: | Beirdo: the VERBOSE macro uses a mutex lock |
| [01:47:38] | Beirdo: | yeah, in master/0.24 |
| [01:47:53] | taylorr: | so basically we have it narrowed down to a mutex lock or unlock causes ~11 msec delays |
| [01:47:59] | Beirdo: | in new-logging, there is no macro to speak of, it uses a function |
| [01:48:30] | Beirdo: | which has a very short lock (just long enough to push a pointer onto a queue) |
| [01:48:54] | Beirdo: | should be able to compare in a moment |
| [01:48:57] | taylorr: | well these should be short too since I believe they are free |
| [01:49:01] | Beirdo: | compile's nearly done |
| [01:49:25] | Beirdo: | yeah, but they hold the lock longer (doing cout or cerr, I forget which) |
| [01:49:39] | Chutt: | taylorr, a lock/unlock will generally trigger a reschedule, so if something else is trying to run it could go instead |
| [01:49:42] | Beirdo: | so more chance of waiting for something else |
| [01:49:50] | Beirdo: | and that |
| [01:49:54] | markk: | taylorr: I don't think I'm seeing the issue in latest master. just run through playback of galactica. a few pauses which seem to correlate with those excessive reads where the backend readahead actually has to go direct to disk. |
| [01:50:00] | Chutt: | if with no contention |
| [01:50:03] | markk: | did you apply the filetransfer fix |
| [01:50:05] | markk: | ? |
| [01:50:05] | Chutt: | err, even with no contention |
| [01:50:37] | taylorr: | Chutt: if you do an unlock to a lock that is free shouldn't it return immediately? I'm seeing constant 11 msec FUTEX_WAIT/WAKE calls happening |
| [01:50:44] | Beirdo: | oops, just killed the frontend instead of backend |
| [01:51:04] | taylorr: | markk: you mean to enable the readahead buffer on the backend? |
| [01:51:10] | taylorr: | yes, I enabled that |
| [01:51:18] | Chutt: | taylorr, like i said, it'll generally do a reschedule, so if there are any other tasks trying to run, they could go instead |
| [01:51:57] | taylorr: | ok, I'm wondering what is so busy then |
| [01:52:01] | Chutt: | compare your kernel version and scheduler type to beirdo's? |
| [01:52:27] | taylorr: | 2.6.32-25-generic |
| [01:54:51] | Beirdo: | 2.6.34-rc1-jarod1 |
| [01:55:52] | Beirdo: | http://mythtv.pastebin.ca/2073487 |
| [01:55:54] | Beirdo: | from master |
| [01:55:58] | Chutt: | .32's ancient |
| [01:56:05] | Chutt: | i mean, there's cell phones with newer kernels :p |
| [01:56:22] | Beirdo: | also, what version of Qt is another data point |
| [01:57:28] | Beirdo: | 4.6.2–0ubuntu5.1 |
| [01:57:38] | taylorr: | trying to find out what type of scheduler it uses |
| [01:58:29] | Beirdo: | yeah, not sure how to check that |
| [01:58:32] | taylorr: | Beirdo: it's still fast |
| [01:59:46] | Beirdo: | yeah |
| [02:04:46] | PointyPumper (PointyPumper!~pintlezz@190.244.73.13) has joined #mythtv | |
| [02:09:36] | taylorr: | markk: what kernel are you running? |
| [02:11:37] | markk: | 2.6.35-20-generic (backend that is) |
| [02:12:31] | taylorr: | ok, maybe this old kernel doesn't perform very well |
| [02:12:49] | taylorr: | but you provided logs showing large delays when reading from the backend |
| [02:13:13] | taylorr: | like 480 msec which is an insane amount of time to send a MB or so of data |
| [02:22:17] | markk: | taylorr: I'm not sure how much that is improved now that the backend readahead is working. on that galactica clip, I'm still seeing the occasional large wait which I'm pretty sure is because those really big 'catchups' of 10–20MB are exhausting both buffers (frontend and backend) – and hence the backend as to wait for disc access, which slow us down. |
| [02:22:39] | markk: | slows |
| [02:24:14] | markk: | taylorr: and it also looks like there is the occasional 'random' delay on the backend – which seems to go away the second time it is played. so maybe hardisk cacheing is coming into play as well. |
| [02:25:26] | ** markk can't type today ** | |
| [02:25:34] | taylorr: | markk: I'm seeing the hard disk read() take 15 msec but the entire transactions take hundreds of msecs |
| [02:25:41] | taylorr: | that doesn't make any sense |
| [02:26:37] | taylorr: | from looking Beirdo's strace he may not have an issue with these problematic videos |
| [02:26:47] | taylorr: | Beirdo: do you have a remote frontend with VDPAU? |
| [02:27:15] | Beirdo: | yes on both counts |
| [02:27:21] | taylorr: | markk: I thought the same as you that the disk access time was the problem but it's not |
| [02:28:04] | taylorr: | can you try playing a couple clips we have (after you download them) on remote FE with VDPAU and no vdpaubuffersize= option being set? |
| [02:28:15] | Beirdo: | sure |
| [02:29:11] | taylorr: | sent you PM |
| [02:31:58] | markk: | taylorr: so FileRingBuffer::safe_read(int fd... is always quick itself but something in RingBuffer::run is slowing it down |
| [02:32:12] | taylorr: | markk: exactly |
| [02:32:24] | taylorr: | on my system it's the lock/unlock calls |
| [02:32:51] | taylorr: | even though I believe they are always free it results in ~11 msec delay eveytime it hits them |
| [02:35:08] | taylorr: | markk: it's actually everything that is called via FileTransfer::RequestBlock() |
| [02:38:24] | markk: | taylorr: did you try removing the locking in RequestBlock (or maybe change that QMutexLocker to just straight lock/unlock of lock) |
| [02:39:24] | Dave123 (Dave123!~dave@cpe-74-74-200-106.rochester.res.rr.com) has joined #mythtv | |
| [02:39:48] | Dave123 (Dave123!~dave@cpe-74-74-200-106.rochester.res.rr.com) has quit (Client Quit) | |
| [02:40:21] | taylorr: | markk: yes I removed that one but it didn't resolve the issue |
| [02:40:35] | taylorr: | removing the VERBOSE and most of the locks seem to help a lot though |
| [02:41:00] | taylorr: | also sock->writeData() completes quickly as well |
| [02:41:24] | taylorr: | so the 2 main functions that you would think take the most time are a fraction of the total time |
| [02:43:14] | markk: | taylorr: slightly different topic – any idea if ffmpeg gives you any information on variable bit rate? |
| [02:44:00] | markk: | or whether there is an easy way to determine the actual bitrate for a cropped mkv? |
| [02:44:37] | taylorr: | markk: I believe they just take duration and filesize to determine it |
| [02:44:46] | taylorr: | if duration is wrong then the bitrate is wrong |
| [02:45:02] | taylorr: | not sure what type of stream sampling it does to find the bitrate of each stream though |
| [02:46:31] | taylorr: | markk: the only way to get a reasonable approx of bitrate if the duration is wrong is to read part of the file and take the duration of that section and the byte pos and use it to determine it |
| [02:46:50] | taylorr: | we should be able to easily keep track of the actually average bitrate while playing back any video |
| [02:49:54] | markk: | taylorr: I'm just thinking about how we start to adjust the buffersize based on known factors. |
| [02:50:41] | markk: | Captain_Murdoch: any reason you can think of not to backport that RemotFile/readahead fix? |
| [02:56:36] | Captain_Murdoch: | the buffer->start() one? not that I know of. it was probably an oversight when the ringbuffer code was reworked. |
| [02:57:06] | Captain_Murdoch: | not sure if that was from daniel's rework or if it's been even longer than that. |
| [02:57:22] | taylorr: | markk, Captain_Murdoch: are you guys sure that in 0.23-fixes and earlier we ran the readahead buffer on the backend? |
| [02:57:41] | taylorr: | I just don't see how it could be that beneficial |
| [02:58:19] | taylorr: | since we already have a readahead buffer on the frontend |
| [03:02:58] | markk: | taylorr: looks like the readahead hasn't been started for some time. I can see it having a benefit if there is a transient issue with disc access. |
| [03:03:17] | markk: | (which may help to all of those pause discussions) |
| [03:03:21] | taylorr: | sure, I agree |
| [03:03:21] | markk: | with |
| [03:03:35] | taylorr: | it shouldn't hurt |
| [03:04:32] | Captain_Murdoch: | markk, yeah, I came to the same conclusion. I'm looking at 0.21-fixes source and it doesn't look like the readahead was started for file transfers there either as far as I can see. |
| [03:05:17] | Captain_Murdoch: | I thought it used to be started automatically, but see that even as far back as 0.21, you had to call Start() to get it started, even if you said to use readahead in the ctor. |
| [03:06:48] | taylorr: | markk: well, I guess I'm done looking at this problem – I've no idea why I'm having these excessive FUTEX_WAIT calls – maybe I should just upgrade my kernel and hope they go away |
| [03:06:53] | Captain_Murdoch: | only thing I can see it affecting is seek times potentially. theoreticaly, during playback, it just gives us a twice as large buffer. |
| [03:08:26] | taylorr: | having the readahead active on the backend might also help in situation where we are streaming to multiple frontends concurrently |
| [03:09:02] | taylorr: | I imagine disk access would be more chaotic |
| [03:09:57] | taylorr (taylorr!~taylorr@unaffiliated/elmojo) has quit (Remote host closed the connection) | |
| [03:12:20] | taylorr (taylorr!~taylorr@cpe-173-095-144-220.nc.res.rr.com) has joined #mythtv | |
| [03:12:20] | taylorr (taylorr!~taylorr@unaffiliated/elmojo) has joined #mythtv | |
| [03:12:20] | taylorr (taylorr!~taylorr@cpe-173-095-144-220.nc.res.rr.com) has quit (Changing host) | |
| [03:42:47] | GreyFoxx: | markk: Great, glad it's working. I'll clean it up, and so some more tests tomorrow and if all is well I'll commit it |
| [03:43:07] | kormoc_afk is now known as kormoc | |
| [03:46:24] | GreyFoxx: | fixed the stray else too :) |
| [03:58:28] | taylorr (taylorr!~taylorr@unaffiliated/elmojo) has joined #mythtv | |
| [04:24:37] | zombor (zombor!~zombor_@kohana/developer/zombor) has joined #mythtv | |
| [04:32:23] | Goga777 (Goga777!~Goga777@shpd-92-101-139-238.vologda.ru) has joined #mythtv | |
| [04:55:34] | analogue_ (analogue_!~analogue@c-98-222-42-225.hsd1.il.comcast.net) has quit (Quit: leaving) | |
| [04:56:12] | analogue_ (analogue_!~analogue@c-98-222-42-225.hsd1.il.comcast.net) has joined #mythtv | |
| [05:03:22] | analogue_ (analogue_!~analogue@c-98-222-42-225.hsd1.il.comcast.net) has quit (Quit: leaving) | |
| [05:13:09] | jya (jya!~jyavenard@mythtv/developer/jya) has quit (Quit: jya) | |
| [05:23:10] | analogue_ (analogue_!~analogue@c-98-222-42-225.hsd1.il.comcast.net) has joined #mythtv | |
| [05:23:36] | Goga777 (Goga777!~Goga777@shpd-92-101-139-238.vologda.ru) has quit (Remote host closed the connection) | |
| [05:29:44] | zombor (zombor!~zombor_@kohana/developer/zombor) has quit (Remote host closed the connection) | |
| [05:30:22] | Beirdo: | taylorr: no problems at all with the Cars one |
| [05:30:56] | Beirdo: | BSG is playing now, it got one waited 103ms for video buffers at a massive scene change. |
| [05:31:12] | Beirdo: | make that a few |
| [05:32:45] | Beirdo: | you know what would be cool to have (in the OSD)... a current bitrate monitor ... say averaged over 1s |
| [05:33:16] | Beirdo: | I've seen it on DVD players before. might be a bit tricky to implement |
| [05:34:22] | taylorr: | Beirdo: thanks for testing |
| [05:34:30] | taylorr: | I upgraded my kernel but no joy |
| [05:34:48] | Beirdo: | hmm |
| [05:35:11] | Beirdo: | which version of Qt? |
| [05:37:23] | Beirdo: | and now I find I have some more work to do on nuvexport. great |
| [05:39:12] | taylorr: | how can you easily tell what version you have installed? |
| [05:39:38] | Beirdo: | for me, I just used apt-cache policy libqt4-dev |
| [05:39:54] | Beirdo: | but if you're not ubuntu/debian, that likely won't do squat |
| [05:41:26] | taylorr: | Beirdo: 4:4.6.2–0ubuntu5.2 |
| [05:41:58] | Beirdo: | 4:4.6.2–0ubuntu5.1 |
| [05:42:08] | Beirdo: | OK, so it's likely not that |
| [05:42:28] | Beirdo: | I haven't applied that update, it seems |
| [05:43:56] | taylorr: | wonder if I've got some hardware issue with interrupts |
| [05:44:25] | Beirdo: | crop=10:6:700:468 |
| [05:44:36] | Beirdo: | hahah, seems ffmpeg changed the order on me |
| [05:45:03] | Beirdo: | that tells it to crop 10x6 pixels out, and then after, I have it scaling to 512x384 |
| [05:45:11] | Beirdo: | not quite what I wanted |
| [05:50:12] | Beirdo: | let's try that with crop-700:468:10:6 |
| [05:57:51] | Beirdo: | this is pretty: |
| [05:57:52] | Beirdo: | 2011-06–01 22:57:14.068793 MythUIProgressDialog::customEvent() Error, event claims to be a progress update but fails to cast |
| [06:04:34] | Beirdo: | ooh, divx with ffmpeg, definitely borked |
| [06:05:12] | Beirdo: | just running the same short cut through all the exporters :) |
| [06:08:51] | natanojl (natanojl!~jonatan@c83-252-237-63.bredband.comhem.se) has joined #mythtv | |
| [06:51:21] | natanojl (natanojl!~jonatan@c83-252-237-63.bredband.comhem.se) has quit (Ping timeout: 252 seconds) | |
| [06:56:11] | Beirdo: | ok, bed |
| [07:18:46] | stoffel (stoffel!~quassel@p57B4BFDB.dip.t-dialin.net) has joined #mythtv | |
| [07:33:35] | andreax (andreax!~andreaz@p57B92F30.dip.t-dialin.net) has joined #mythtv | |
| [08:04:30] | jpabq (jpabq!~jpabq@mythtv/developer/jpabq) has quit (Quit: ZNC - http://znc.sourceforge.net) | |
| [08:05:34] | jpharvey (jpharvey!~jpharvey@host86-135-80-177.range86-135.btcentralplus.com) has quit (Ping timeout: 250 seconds) | |
| [08:06:57] | jpharvey (jpharvey!~jpharvey@host86-135-80-177.range86-135.btcentralplus.com) has joined #mythtv | |
| [08:07:28] | jpabq (jpabq!~jpabq@mythtv/developer/jpabq) has joined #mythtv | |
| [08:08:53] | okolsi: | GreyFoxx: your original patch works here, phone apps discover backend again |
| [08:08:56] | stoffel (stoffel!~quassel@p57B4BFDB.dip.t-dialin.net) has quit (Remote host closed the connection) | |
| [08:12:55] | okolsi: | GreyFoxx, stuartm: check #9441, upnp music issue was discovered, reported and patched 5 months ago ;) can be closed now |
| [08:17:17] | MaverickTech (MaverickTech!~MaverickT@111.86.233.220.static.exetel.com.au) has quit (Read error: Connection reset by peer) | |
| [08:20:39] | fphillips (fphillips!~fp@adsl-71-145-161-95.dsl.austtx.sbcglobal.net) has quit (Quit: Leaving) | |
| [08:23:40] | MaverickTech (MaverickTech!~MaverickT@111.86.233.220.static.exetel.com.au) has joined #mythtv | |
| [08:31:51] | okolsi: | GreyFoxx: upnp music works now, but recordings and videos both produce SQL errors here, similar like the music problem was. |
| [09:02:24] | stoffel (stoffel!~quassel@p57B4BFDB.dip.t-dialin.net) has joined #mythtv | |
| [09:09:57] | Gibby (Gibby!~Gibby@204.118.10.244) has quit (Ping timeout: 255 seconds) | |
| [09:10:45] | Gibby (Gibby!~Gibby@204.118.10.244) has joined #mythtv | |
| [09:16:42] | GreyFoxx: | oko: Can you show me some output from the Video/Recordings errors? And what section you were navigating at the time ? |
| [09:17:44] | okolsi: | GreyFoxx: just a sec |
| [09:19:31] | Gibby (Gibby!~Gibby@204.118.10.244) has quit (Ping timeout: 244 seconds) | |
| [09:20:41] | okolsi: | GreyFoxx: this when navigating Recordings -> By Channel -> 4 Nelonen (and no programs can be seen): http://pastebin.com/e38Q8VHG |
| [09:20:44] | Gibby (Gibby!~Gibby@204.118.10.244) has joined #mythtv | |
| [09:21:21] | okolsi: | looks like that By Channel has the problem, other Recordings categories are working |
| [09:22:21] | GreyFoxx: | k |
| [09:22:29] | GreyFoxx: | I never tried that particular one :) |
| [09:24:55] | okolsi: | GreyFoxx: videos case: Videos -> All Videos -> you can see all the videos, select one for the playback and: http://pastebin.com/6WSP69CY |
| [09:35:49] | GreyFoxx: | okol: For the video one can you try: http://pastebin.ca/2073626 |
| [09:40:01] | GreyFoxx: | the byChannel one is wierd since I can see where the first part of the query is coming from, and the only spot that seems to touch that is BuildItemQuery() yet some of what BuildItemQuery adds to the query is not in your log output... That one will require more testing :) |
| [09:40:36] | stoffel (stoffel!~quassel@p57B4BFDB.dip.t-dialin.net) has quit (Read error: Operation timed out) | |
| [09:57:49] | aloril (aloril!~aloril@dsl-tkubrasgw3-fe7ef900-153.dhcp.inet.fi) has quit (Ping timeout: 246 seconds) | |
| [10:05:02] | mike|3 (mike|3!~mike@c-24-21-63-118.hsd1.or.comcast.net) has quit (Remote host closed the connection) | |
| [10:05:53] | mike|2 (mike|2!~mike@c-24-21-63-118.hsd1.or.comcast.net) has joined #mythtv | |
| [10:10:33] | natanojl (natanojl!~jonatan@c83-252-237-63.bredband.comhem.se) has joined #mythtv | |
| [10:11:23] | aloril (aloril!~aloril@dsl-tkubrasgw3-fe7ef900-153.dhcp.inet.fi) has joined #mythtv | |
| [10:12:44] | Gibby (Gibby!~Gibby@204.118.10.244) has quit (Ping timeout: 244 seconds) | |
| [10:13:14] | Gibby (Gibby!~Gibby@204.118.10.244) has joined #mythtv | |
| [10:23:17] | eharris (eharris!~eharris@99-179-7-82.lightspeed.austtx.sbcglobal.net) has quit (Ping timeout: 252 seconds) | |
| [10:24:38] | eharris (eharris!~eharris@99-179-7-82.lightspeed.austtx.sbcglobal.net) has joined #mythtv | |
| [10:30:15] | eharris (eharris!~eharris@99-179-7-82.lightspeed.austtx.sbcglobal.net) has quit (Ping timeout: 258 seconds) | |
| [10:31:47] | eharris (eharris!~eharris@99-179-7-82.lightspeed.austtx.sbcglobal.net) has joined #mythtv | |
| [11:03:19] | okolsi: | GreyFoxx: I'll test the patch little bit later |
| [11:09:55] | aloril (aloril!~aloril@dsl-tkubrasgw3-fe7ef900-153.dhcp.inet.fi) has quit (Ping timeout: 246 seconds) | |
| [11:16:41] | Gibby (Gibby!~Gibby@204.118.10.244) has quit (Ping timeout: 240 seconds) | |
| [11:17:44] | Gibby (Gibby!~Gibby@204.118.10.244) has joined #mythtv | |
| [11:19:07] | cocoa117 (cocoa117!~cocoa117@wk-28-147.guest.rdg.ac.uk) has joined #mythtv | |
| [11:22:31] | aloril (aloril!~aloril@dsl-tkubrasgw3-fe7ef900-153.dhcp.inet.fi) has joined #mythtv | |
| [11:23:56] | Dave123-road (Dave123-road!~dave@cpe-74-74-200-106.rochester.res.rr.com) has joined #mythtv | |
| [11:30:15] | aloril (aloril!~aloril@dsl-tkubrasgw3-fe7ef900-153.dhcp.inet.fi) has quit (Ping timeout: 260 seconds) | |
| [11:43:55] | aloril (aloril!~aloril@dsl-tkubrasgw3-fe7ef900-153.dhcp.inet.fi) has joined #mythtv | |
| [11:46:51] | gigem (gigem!~david@mythtv/developer/gigem) has quit (Remote host closed the connection) | |
| [11:47:17] | gigem (gigem!~david@host103.16.intrusion.com) has joined #mythtv | |
| [11:47:17] | gigem (gigem!~david@host103.16.intrusion.com) has quit (Changing host) | |
| [11:47:17] | gigem (gigem!~david@mythtv/developer/gigem) has joined #mythtv | |
| [11:51:14] | Dave123 (Dave123!~dave@cpe-74-74-200-106.rochester.res.rr.com) has joined #mythtv | |
| [11:59:14] | Gibby (Gibby!~Gibby@204.118.10.244) has quit (Quit: ZNC - http://znc.sourceforge.net) | |
| [12:00:02] | Gibby (Gibby!~Gibby@204.118.10.244) has joined #mythtv | |
| [12:34:28] | cocoa117 (cocoa117!~cocoa117@wk-28-147.guest.rdg.ac.uk) has quit (Quit: Leaving) | |
| [12:36:01] | justinh (justinh!~justin@cpc1-salf4-0-0-cust69.10-2.cable.virginmedia.com) has quit (Quit: leaving) | |
| [12:44:08] | okolsi: | GreyFoxx: patch fixes video playback :) while you are working with UPnP stuff, could you check tiny logging fix in #9816 |
| [12:48:58] | danielk22 (danielk22!~danielk@96.57.9.142) has joined #mythtv | |
| [12:57:46] | eharris (eharris!~eharris@99-179-7-82.lightspeed.austtx.sbcglobal.net) has quit (Ping timeout: 248 seconds) | |
| [12:59:14] | eharris (eharris!~eharris@99-179-7-82.lightspeed.austtx.sbcglobal.net) has joined #mythtv | |
| [13:01:30] | GreyFoxx: | playback to Both are now commited :) |
| [13:01:35] | GreyFoxx: | oops |
| [13:01:46] | GreyFoxx: | That should have just been "Both are now commited :)" |
| [13:07:30] | okolsi: | nice :) |
| [13:15:57] | GreyFoxx: | A Fix for the By Channel reecordings is in now |
| [13:35:22] | okolsi: | GreyFoxx: sounds good.. how would you feel adding couple of new ways to access music through upnp? E.g. "by artist", "by genre" etc? I could see if I could make a patch.. or do you have any such plans? |
| [13:38:17] | GreyFoxx: | I have no plans for upnp in anyway, but if you want to do up a patch I'll check it out :) |
| [13:38:37] | okolsi: | k |
| [13:50:51] | GreyFoxx: | Though my 5k videos entries take the cds 5 seconds to generate the list to send back to the client |
| [13:51:00] | GreyFoxx: | so I might see if I can speed that up a little |
| [13:58:53] | danielk22: | GreyFoxx: Does MythVideo use ProgramInfo entries yet? I was thinking of adding incremental list sending/processing to PBB to handle large collections, I'm wondering if MythVideo could piggyback off that. |
| [13:59:25] | GreyFoxx: | Not that I see, everything is in the videometadata table |
| [13:59:39] | GreyFoxx: | but I haven't look through the new metadata library |
| [14:01:03] | danielk22: | GreyFoxx: ok, I remember that being talked about, and it was something I kept in mind during the ProgramInfo refactoring. But I haven't been following development as closely as I'd like in the last 6 months. |
| [14:02:19] | andreax (andreax!~andreaz@p57B92F30.dip.t-dialin.net) has quit (Read error: Connection reset by peer) | |
| [14:13:11] | stuartm: | danielk22: I'd started writing a VideoInfo class a few months back but then abandoned it |
| [14:13:26] | zombor (zombor!~zombor_@kohana/developer/zombor) has joined #mythtv | |
| [14:15:47] | j-rod|afk is now known as j-rod | |
| [14:23:14] | danielk22: | stuartm: Abandoned for lack of time? Or it just wasn't a good fit? i.e. does it makes sense for anyone else to pursue it? |
| [14:25:37] | stuartm: | lack of time |
| [14:25:59] | stuartm: | I think it's worth doing |
| [14:26:27] | stuartm: | there is a lot of common ground |
| [14:27:06] | stuartm: | but then again since then iamlindoro has done work on the new metadata classes, he might have been taking it in another direction |
| [14:31:51] | taylorr (taylorr!~taylorr@unaffiliated/elmojo) has quit (Remote host closed the connection) | |
| [14:34:02] | brienna (brienna!~Chetster@westbrook-1-pt.tunnel.tserv4.nyc4.ipv6.he.net) has joined #mythtv | |
| [14:35:32] | brienna (brienna!~Chetster@westbrook-1-pt.tunnel.tserv4.nyc4.ipv6.he.net) has quit (Client Quit) | |
| [14:37:07] | brienna (brienna!~Chetster@westbrook-1-pt.tunnel.tserv4.nyc4.ipv6.he.net) has joined #mythtv | |
| [14:38:13] | taylorr (taylorr!~taylorr@cpe-173-095-144-220.nc.res.rr.com) has joined #mythtv | |
| [14:38:14] | taylorr (taylorr!~taylorr@unaffiliated/elmojo) has joined #mythtv | |
| [14:38:14] | taylorr (taylorr!~taylorr@cpe-173-095-144-220.nc.res.rr.com) has quit (Changing host) | |
| [14:47:13] | GreyFoxx: | I suspect that http://code.mythtv.org/trac/ticket/9820 's problem is more related to the upnp issues I patched yesterday than anything else |
| [14:53:21] | okolsi: | for recordings, UPnP lists all recordings including stuff in Deleted and LiveTV recgroups. unfortunately there's no easy one-liner fix for that |
| [14:56:29] | okolsi: | GreyFoxx: one way to speed up upnp video listing (and recordings and maybe music) would be to limit huge number of SQL queries related to storagegroups. now it seems to make one query for each video/recording and it might be possible to cache this somehow: http://pastebin.com/NZr96F03 |
| [14:57:55] | taylorr: | Beirdo: I'm thinking up updating to master to see if the slow FUTEX_WAIT syscalls go away or not – how stable is master right now? |
| [15:07:29] | sphery: | danielk22 / stuartm: I think iamlindoro is waiting on me to get the recordedfile schema in place and start conversion of MythVideo to use it. At that point, switching MythVideo to ProgramInfo (or at least some related class) should be much easier |
| [15:09:24] | sphery: | okolsi: FWIW, the recordedfile schema changes will make the SG query/file system search (where the latter is likely the slow part) less resource intensive (we'll actually have a "last-known location" to check first) |
| [15:17:31] | gigem (gigem!~david@mythtv/developer/gigem) has quit (Remote host closed the connection) | |
| [15:17:58] | gigem (gigem!~david@mythtv/developer/gigem) has joined #mythtv | |
| [15:31:06] | gregL (gregL!~greg@cpe-74-76-125-87.nycap.res.rr.com) has quit (Read error: Connection reset by peer) | |
| [15:37:36] | sphery: | danielk22 / Captain_Murdoch : FWIW, re: http://code.mythtv.org/trac/ticket/9819 , if it is the dispatchNow() in sendPlaybackEnd() , the patch I just attached seems to remove the last 2 uses of dispatchNow(), so we might be best served to get rid of that function to prevent further issues with it. And, future code could be designed so it doesn't need blocking functionality. Also, I have no idea if that patch will break the playback start/end ... |
| [15:37:42] | sphery: | ... events (meaning if they will need to be redesigned to not need blocking). |
| [15:47:07] | gregL (gregL!~greg@cpe-74-76-125-87.nycap.res.rr.com) has joined #mythtv | |
| [15:54:36] | abqjp (abqjp!~abqjp@174-28-187-116.albq.qwest.net) has quit (Quit: abqjp) | |
| [16:04:16] | abqjp (abqjp!~abqjp@97-119-171-42.albq.qwest.net) has joined #mythtv | |
| [16:10:08] | taylorr: | danielk22: wondering if you have any ideas on why my mythbackend app has such poor performance when accessing locks – here is an strace of a thread handling a block request -> http://mythtv.pastebin.ca/2073430 – simple things like executing a VERBOSE call go through a few locks which take almost 11 msecs each! – look at lines 90–99 |
| [16:11:20] | taylorr: | basically any lock triggers this 11 msec FUTEX_WAIT – as far as I can tell no other process is trying to use the lock |
| [16:11:50] | taylorr: | on the same system I don't see this issue with mythfrontend |
| [16:46:52] | natanojl (natanojl!~jonatan@c83-252-237-63.bredband.comhem.se) has quit (Ping timeout: 250 seconds) | |
| [16:47:00] | gigem (gigem!~david@mythtv/developer/gigem) has quit (Remote host closed the connection) | |
| [16:47:27] | gigem (gigem!~david@host103.16.intrusion.com) has joined #mythtv | |
| [16:47:27] | gigem (gigem!~david@host103.16.intrusion.com) has quit (Changing host) | |
| [16:47:27] | gigem (gigem!~david@mythtv/developer/gigem) has joined #mythtv | |
| [17:01:45] | danielk22: | taylorr: 11 ms.. that sounds like a reschedule happened and somebody else got to run. |
| [17:02:15] | taylorr: | danielk22: why is it always 11 ms and if the lock was free why did a reschedule happen |
| [17:02:28] | taylorr: | I don't see the frontend app suffer the same issue |
| [17:03:18] | taylorr: | I'm using a profile build... would using a release build change anything? |
| [17:05:25] | danielk22: | taylorr: if the mythbackend process is using most of the cycles then someone else gets to run, if you have 100 ticks per second it's they get up to 10 ms |
| [17:07:22] | taylorr: | danielk22: the system is extremely idle and it ALWAYS waits 11 msec |
| [17:07:59] | danielk22: | *shrug* I don't know. |
| [17:08:04] | taylorr: | I don't understand what else could be taking over – any ideas on how to tell what process is using that 11 msec |
| [17:08:30] | Chutt: | could just be another backend thread as well |
| [17:09:15] | taylorr: | I did a tryLock and they are always free so it's not lock contention so as Chutt also mentioned it must be a reschedule |
| [17:13:21] | taylorr: | I'll just run mythbackend under gdb next and see what all the threads are doing |
| [17:17:09] | andreax (andreax!~andreaz@p57B92F30.dip.t-dialin.net) has joined #mythtv | |
| [17:23:56] | taylorr: | danielk22: you're right the system is using 100 ticks/sec so the 10 msec + overhead would give us the 11 msec |
| [17:24:41] | taylorr: | I'll rerun the backend and turn off as much as possible to see if it's one of those threads and if not I'll have to do gdb and hope it provides some insight |
| [17:29:20] | knightr (knightr!~knightr@mythtv/developer/knightr) has quit (Ping timeout: 250 seconds) | |
| [17:29:47] | knightr (knightr!~knightr@mythtv/developer/knightr) has joined #mythtv | |
| [17:30:38] | knightr (knightr!~knightr@mythtv/developer/knightr) has quit (Read error: Connection reset by peer) | |
| [17:31:07] | knightr (knightr!~knightr@mythtv/developer/knightr) has joined #mythtv | |
| [17:31:20] | danielk22: | taylorr: You might also want to upgrade your kernel, the 2.6 series has had some problems with too clever CPU and disk schedulers. |
| [17:32:58] | taylorr: | already changed from 2.6.32 to 2.6.35 and no improvement |
| [17:33:09] | taylorr: | they are both stock ubuntu |
| [17:38:00] | knightr (knightr!~knightr@mythtv/developer/knightr) has quit (Ping timeout: 250 seconds) | |
| [17:38:10] | knightr (knightr!~knightr@mythtv/developer/knightr) has joined #mythtv | |
| [17:39:39] | danielk22: | taylorr: That should be recent enough. Whatever it is it looks like it's using it's full time-slice, so maybe something CPU bound like preview generation. |
| [17:40:14] | taylorr: | danielk22: would a full gdb backtrace with all the threads be helpful |
| [17:40:54] | danielk22: | taylorr: I'm assuming it's not a 10 ms delay that is causing the problem you are experiencing though? The scheduler will return and you would have lost that 10 ms soon anyway. |
| [17:42:12] | danielk22: | taylorr: If you need lower latency, like on a frontend, I recommend setting the ticks higher, to 1000 maybe. |
| [17:42:53] | taylorr: | danielk22: the backend needs lower latency too as it responds to requests such as streaming data to a frontend |
| [17:43:09] | taylorr: | if it has a lot of delay the the frontend can suffer |
| [17:43:38] | taylorr: | wouldn't setting the ticks higher need a custom kernel compile? |
| [17:45:18] | danielk22: | taylorr: Ubuntu has a preempt kernel, I believe most distros do. The standard/server kernel isn't best suited for anything to do with A/V. |
| [17:46:55] | Beirdo: | I would think that if we can't successfully stream on a 10ms timeslot, we need to rethink how we stream |
| [17:47:11] | danielk22: | still the backend shouldn't need to respond in 10ms, we have buffering for that. |
| [17:47:32] | Beirdo: | like... not start playback until we have 1s worth of data, not immediate, or the like |
| [17:48:27] | Beirdo: | maybe I'm just caffeine deprived, but there just seems to be something systematically wrong with our setup |
| [17:48:42] | danielk22: | Beirdo: We don't start playback until we have some buffer fill. |
| [17:49:03] | taylorr: | It's not just a single 10ms delay! |
| [17:49:38] | Beirdo: | it seems we run too close to buffer empty though. The frontend ideally would have enough data to deal with momentary delays in the order of 100ms+ |
| [17:49:50] | taylorr: | it's 10+ msec everytime we call a stupid lock/unlock so it accumulates to several 100 msec for a response back |
| [17:49:54] | Beirdo: | yeah |
| [17:50:01] | Beirdo: | I understand that :) |
| [17:50:42] | Beirdo: | if we aimed closer to like buffer 1/4 full as a low water mark, it might work better. But let me ingest my coffee :) |
| [17:50:43] | danielk22: | taylorr: Then it's probably not a scheduler steal. |
| [17:51:51] | danielk22: | taylorr: what architecture is this? i7 i5 ? |
| [17:51:54] | taylorr: | here is a gdb backtrace of all the threads -> http://mythtv.pastebin.ca/2073789 |
| [17:52:00] | taylorr: | core i3 |
| [17:53:01] | taylorr: | yuck, why is the EIT scanner running |
| [17:53:43] | Beirdo: | I see EIT Event threads on my system too with EIT disabled, but I've just ignored it so fa |
| [17:53:46] | Beirdo: | far |
| [17:54:12] | danielk22: | Beirdo: just change "fill_threshold = kBufferSize / 8;" to "fill_threshold = kBufferSize / 4;" but maybe just doubling the buffer would be better. |
| [17:54:53] | taylorr: | danielk22: did that backtrace show anything suspect? |
| [17:54:54] | danielk22: | Beirdo: I think a better solution might be to size up the buffer if either the bitrate is high or if we see these issues. |
| [17:55:19] | Beirdo: | agreed, having a sliding threshold based on current bitrate would be good if we could |
| [17:55:49] | danielk22: | Beirdo: The very fact that we have a single buffer size for files at 4mbit and 40mbit is a probably not the most efficient. |
| [17:56:05] | Beirdo: | agreed :) wonder what bitrate it's tuned for? |
| [17:56:37] | Beirdo: | sliding threshold and/or sliding buffer size |
| [17:57:59] | danielk22: | Beirdo: The buffer size was tuned for 4mbit, but it the read block sizes are tuned for 2–19 mbit. |
| [17:58:11] | Beirdo: | eek :) |
| [17:58:26] | Beirdo: | I can see why we have some issues at higher bitrates |
| [17:58:50] | danielk22: | It's really a wonder that it has scaled as well as it has.. faster processors and disks have probably helped. |
| [17:59:14] | Beirdo: | yeah, it's one of those "this WORKS?" things :) |
| [17:59:16] | taylorr: | another very important variable is the burstiness of the reader |
| [17:59:26] | Beirdo: | and gige helps too |
| [17:59:43] | danielk22: | taylorr: all those threads are sleeping.. |
| [17:59:45] | taylorr: | matroska does cluster reads depending on how the file was muxed |
| [18:00:14] | taylorr: | Beirdo: do you have a custom kernel? |
| [18:00:33] | Beirdo: | the customizations were to do IR on the HDPVR |
| [18:00:47] | Beirdo: | which I haven't done for a while, just haven't changed my kernel since |
| [18:01:04] | slipcon (slipcon!~sjlipco@pool-96-255-3-66.washdc.fios.verizon.net) has joined #mythtv | |
| [18:01:57] | Beirdo: | I still have the .config file if there's anything you'd like me to check |
| [18:01:59] | danielk22: | Beirdo: The problem is with the current implementation we'd need to grab a big ugly lock on everything to resize the buffer. |
| [18:02:03] | taylorr: | can a program tell the kernel via a syscall how to schedule itself? |
| [18:02:51] | Beirdo: | danielk22: hmm, yeah. There might be a more elegant way, but beats me what it would be right now |
| [18:03:14] | Beirdo: | maybe having the buffer as a linked list? |
| [18:03:22] | danielk22: | taylorr: Umm, it can request real-time processing but there is a complicated permissions model these days, I don't know how you grant an application permission. |
| [18:03:41] | Beirdo: | then expanding it is as "simple" as adding another item to the end of the list |
| [18:05:31] | Beirdo: | it looks like I'm scheduling using CGROUPS if that makes any sense |
| [18:06:57] | Beirdo: | default IOSCHED=deadline |
| [18:07:38] | taylorr: | Beirdo: where'd you find that info? |
| [18:07:47] | Beirdo: | in my kernel's .config file |
| [18:08:29] | danielk22: | Beirdo: Heh, were it so simple.. But it doesn't look like a full lock would be that big a deal, we do it for ReadBufFree() and ReadBufAvail(); |
| [18:08:38] | Beirdo: | oh. and CONFIG_PREEMPT_NONE=y |
| [18:08:58] | Beirdo: | danielk22: yeah, "simple" is usually not simple in the end anyways :) |
| [18:09:44] | taylorr: | Beirdo: your kernel is distinctly different than mine |
| [18:09:55] | Beirdo: | yup |
| [18:09:58] | taylorr: | you should try a stock kernel and see if you have the same issues as I do |
| [18:10:21] | Beirdo: | I could try that tonight, hopefully |
| [18:10:26] | danielk22: | Beirdo: I did rewrite TFW to use a deque of buffers recently, but RingBuffer changes are bit more intense. |
| [18:10:34] | taylorr: | looking at the default Ubuntu .config |
| [18:11:07] | taylorr: | # CONFIG_PREEMPT_NONE is not set |
| [18:11:19] | Beirdo: | and the two after? |
| [18:11:20] | taylorr: | CONFIG_DEFAULT_IOSCHED="cfq" |
| [18:11:33] | Beirdo: | CONFIG_PREEMPT_VOLUNTARY or CONFIG_PREEMPT |
| [18:11:43] | danielk22: | I don't know if the DVD/BD RingBuffers are really correct either, I only audited the base class and FileRingBuffer for lock contention and deadlocks. |
| [18:11:46] | taylorr: | CONFIG_PREEMPT_VOLUNTARY=y |
| [18:11:46] | taylorr: | # CONFIG_PREEMPT is not set |
| [18:12:02] | Beirdo: | K. |
| [18:12:24] | taylorr: | Beirdo: what do you have for those? and how did you obtain those configure options |
| [18:12:46] | Beirdo: | CONFIG_DEFAULT_IOSCHED="deadline" |
| [18:12:59] | Beirdo: | CONFIG_PREEMPT_NONE=y |
| [18:12:59] | Beirdo: | # CONFIG_PREEMPT_VOLUNTARY is not set |
| [18:12:59] | Beirdo: | # CONFIG_PREEMPT is not set |
| [18:13:20] | jams: | Beirdo- did you set it to deadline? |
| [18:13:26] | Beirdo: | I'm looking to see if I can find the difference between the preempts |
| [18:13:54] | Beirdo: | jams: I may have |
| [18:14:03] | Beirdo: | it was almost a year ago at this point :) |
| [18:14:20] | jams: | just curious, I wasn't aware of any distro that used deadline as the default |
| [18:16:18] | taylorr: | danielk22: would you think that a device (capture card, etc) could generate a lot of interrupt processing and cause this sort of issue? |
| [18:16:35] | taylorr: | I'm doubtful it's my problem since no other program has these issues |
| [18:17:31] | andrewju (andrewju!~Miranda@81.200.112.228) has joined #mythtv | |
| [18:17:54] | taylorr: | Beirdo: seems like Mark was running a default Ubuntu kernel and he had REQUEST_BLOCKs take 480 msec! |
| [18:18:04] | taylorr: | which is in-line with what I'm seeing |
| [18:18:39] | Beirdo: | yuck! |
| [18:18:56] | Beirdo: | OK, I'll do my best to try a recent stock kernel tonight |
| [18:19:24] | Beirdo: | it could be that I actually intentionally configed the kernel like that, but it was nearly a year ago, and I just don't remember :) |
| [18:21:26] | taylorr: | Beirdo: well, maybe you solved the mystery and didn't know it :) |
| [18:21:29] | jams: | don't know if it helps with your testing but you can change the schedular on the fly, per disk |
| [18:22:17] | jams: | *scheduler |
| [18:22:43] | Beirdo: | yeah, coulda been |
| [18:22:45] | Beirdo: | :) |
| [18:23:00] | Beirdo: | it certainly shows why my straces look so different from yours |
| [18:23:12] | Beirdo: | yours *can* preempt, mine can't :) |
| [18:23:46] | Beirdo: | as for I/O... CFQ seems to make sense in a general case (be fair to all processes) |
| [18:24:06] | Beirdo: | but on a backend, 2 processes are doing hte majority of IO... mysql and mythbackend |
| [18:24:42] | danielk22: | taylorr: no, even a bad scheduler should not cause you to lose so many slices that a request block would take nearly half a second. |
| [18:24:44] | Beirdo: | I'd be concerned that CFQ might limit the IO of these for the benefit of fairness to other processes that aren't using IO much anyways |
| [18:25:18] | Beirdo: | danielk22: well, if the thread gets preempted at every mutex.lock... I could see it slowing it down a lot |
| [18:25:24] | danielk22: | taylorr: unless the system was under extremely heavy load which you reported it is not. |
| [18:25:27] | sphery: | taylorr: FWIW, I'm using CONFIG_HZ=1000 and CONFIG_NO_HZ (tickless kernel with 1000Hz slices) on both frontend and backend, so it's probably not just the locking/rescheduling causing the vdpau issue |
| [18:26:02] | danielk22: | Beirdo: but it wouldn't be, you only get pre-empted if something else can run. |
| [18:26:11] | Beirdo: | yeah, CONFIG_HZ=1000 here |
| [18:26:17] | Beirdo: | danielk22: hmm, true. |
| [18:27:10] | sphery: | taylorr: also, this should give you most of the interesting scheduler/io scheduler related settings for your kernel: zcat /proc/config.gz | grep '\(C\?GROUP\(_SCHED\)\?\|USER_SCHED\|SCHED\(_DEBUG\|STATS\)\|CONFIG_\(IOSCHED\|D EFAULT\)\)' |
| [18:27:15] | Beirdo: | could be another process on the system though, but yeah, on an idle system... hmmm |
| [18:27:35] | sphery: | (yeah, that regex could be much prettier, but whatever :) |
| [18:27:56] | Beirdo: | hehe |
| [18:28:25] | danielk22: | The RingBuffer will behave very badly if reads take more 480ms. It uses the ffmpeg read frequency to determine how much buffering it should be doing. If these are spaced far apart it assumes the bitrate of the stream is low and it doesn't need much of a buffer. |
| [18:28:41] | sphery: | heh, forgot CONFIG_HZ stuff... zcat /proc/config.gz | grep '\(C\?GROUP\(_SCHED\)\?\|USER_SCHED\|SCHED\(_DEBUG\|STATS\)\|CONFIG_\(IOSCHED\|D EFAULT\|HZ\)\)' |
| [18:28:57] | danielk22: | s/more// |
| [18:30:00] | danielk22: | That is the RingBuffer read scaling falls apart if actual disk/network reads take much more than 150 ms. |
| [18:34:38] | Gibby (Gibby!~Gibby@204.118.10.244) has quit (Read error: Operation timed out) | |
| [18:35:38] | brienna (brienna!~Chetster@westbrook-1-pt.tunnel.tserv4.nyc4.ipv6.he.net) has left #mythtv () | |
| [18:36:20] | Gibby (Gibby!~Gibby@204.118.10.244) has joined #mythtv | |
| [18:48:38] | Gibby (Gibby!~Gibby@204.118.10.244) has quit (Ping timeout: 250 seconds) | |
| [18:49:44] | Gibby (Gibby!~Gibby@204.118.10.244) has joined #mythtv | |
| [18:53:41] | justinh (justinh!~justin@cpc1-salf4-0-0-cust69.10-2.cable.virginmedia.com) has joined #mythtv | |
| [18:54:17] | justinh (justinh!~justin@cpc1-salf4-0-0-cust69.10-2.cable.virginmedia.com) has left #mythtv () | |
| [18:59:51] | sphery: | paul-h: Ah, thanks for the info--I had a feeling that it would break that event. Maybe we should just change it to a developer task to remove dispatchNow usage? |
| [19:08:56] | stoffel (stoffel!~quassel@p57B4BFDB.dip.t-dialin.net) has joined #mythtv | |
| [19:12:17] | PointyPumper (PointyPumper!~pintlezz@190.244.73.13) has quit (Ping timeout: 252 seconds) | |
| [19:14:21] | knightr (knightr!~knightr@mythtv/developer/knightr) has quit (Read error: Operation timed out) | |
| [19:15:20] | knightr (knightr!~knightr@mythtv/developer/knightr) has joined #mythtv | |
| [19:19:40] | ^^rcaskey (^^rcaskey!~Rob@dumbledore.athenshousing.org) has joined #mythtv | |
| [19:19:46] | okolsi: | looks like there's a problem with mythtranscode and transcoding with cutlist.. |
| [19:20:02] | PointyPumper (PointyPumper!~pintlezz@190.244.73.13) has joined #mythtv | |
| [19:20:12] | ^^rcaskey: | hello all, I'm consdering getting cable again and this time I have UVerse as an option, what's the situation like there? |
| [19:20:33] | okolsi: | transcode sets player->SetCutList(deleteMap) which causes "cut list has been changed" mark to be added to DB |
| [19:21:02] | okolsi: | then while it's doing the transcode, it checks 60secs later if anyone has modified the cutlist, finds the marker and always aborts |
| [19:21:08] | slipcon (slipcon!~sjlipco@pool-96-255-3-66.washdc.fios.verizon.net) has quit (Quit: Leaving.) | |
| [19:21:52] | okolsi: | not totally sure but it looks like cutlist transcoding cannot work more than 60 seconds for any given file |
| [19:23:44] | Gibby (Gibby!~Gibby@204.118.10.244) has quit (Ping timeout: 250 seconds) | |
| [19:24:44] | Gibby (Gibby!~Gibby@204.118.10.244) has joined #mythtv | |
| [19:24:48] | knightr (knightr!~knightr@mythtv/developer/knightr) has quit (Ping timeout: 240 seconds) | |
| [19:25:28] | knightr (knightr!~knightr@mythtv/developer/knightr) has joined #mythtv | |
| [19:27:17] | sphery: | okolsi: Yeah, reported bug, but I haven't looked into it (though you've given far better info). Would love a patch that fixes it properly -> http://code.mythtv.org/trac/ticket/9729 |
| [19:29:46] | stoffel (stoffel!~quassel@p57B4BFDB.dip.t-dialin.net) has quit (Ping timeout: 248 seconds) | |
| [19:30:12] | okolsi: | sphery: I see.. I did some debugging while testing kdevelop (which seems to work nicely), probably cannot produce proper patch though |
| [19:31:28] | okolsi: | sphery: since that player->SetCustList(deleteMap) probably is supposed to add the cutlist modified entry to DB, my gut feeling would be to just add a boolean or another method that sets cutlist without this DB addition |
| [19:32:07] | okolsi: | sphery: but not sure easy that would be etc.. |
| [19:34:29] | okolsi: | or.... I wonder why transcode checks the modified status, would be much easier if it just would transcode the file based one the cutlist it gets when it is started |
| [19:40:22] | knightr (knightr!~knightr@mythtv/developer/knightr) has quit (Ping timeout: 246 seconds) | |
| [19:41:02] | knightr (knightr!~knightr@mythtv/developer/knightr) has joined #mythtv | |
| [19:41:59] | PointyPumper (PointyPumper!~pintlezz@190.244.73.13) has quit (Ping timeout: 252 seconds) | |
| [19:43:29] | okolsi: | sphery: I'll at least add some info to the ticket |
| [19:51:00] | knightr (knightr!~knightr@mythtv/developer/knightr) has quit (Ping timeout: 240 seconds) | |
| [19:51:36] | knightr (knightr!~knightr@mythtv/developer/knightr) has joined #mythtv | |
| [20:02:30] | sphery: | okolsi: thanks... with the info you've provided, I can likely figure it out much more easily, so that ticket has just jumped up to the top of my TODO |
| [20:03:22] | PointyPumper (PointyPumper!~pintlezz@190.244.73.13) has joined #mythtv | |
| [20:06:47] | okolsi: | sphery: :) i verified the stuff by commenting out the modified cutlist check in transcode and now it runs properly |
| [20:09:51] | sphery: | okolsi: Yeah, I see exactly what's happening. It's due to the auto-saved cutlist stuff. I'll have to rework that a bit (which I had been planning to do for other reasons, anyway). Thanks for providing the missing piece of the description. (I'm traveling this week, so won't get a chance to fix it for a couple days.) |
| [20:11:24] | sphery: | okolsi: I assume you commented out the if (deleteMap.size() > 0) player->SetCutList(deleteMap); stuff in transcode.cpp. Out of curiosity, does it still use the cut list that way (looks like it will, but want to verify) |
| [20:13:38] | okolsi: | sphery: no, I commented out /*if (honorCutList && m_proginfo &&... where QueryMarkupFlag is checked |
| [20:14:22] | okolsi: | sphery: i think that queries the modified entry in DB every 60sec or something like that.. |
| [20:14:25] | sphery: | ah, ok... was just curious--no need to test the other way (since it's not the right fix) |
| [20:15:31] | okolsi: | okay.. I'm staying at home for 2 weeks now and have little bit more than usual time for Myth :) |
| [20:15:53] | sphery: | yeah, we have code to fail a transcode if some frontend edits the cutlist during transcode, but it's tripped up with the auto-save cutlist/undo/redo patch, so I need to rework that |
| [20:24:43] | natanojl (natanojl!~jonatan@c83-252-237-63.bredband.comhem.se) has joined #mythtv | |
| [21:04:59] | Gibby (Gibby!~Gibby@204.118.10.244) has quit (Ping timeout: 240 seconds) | |
| [21:05:07] | stuartm: | paul-h: the scan is now failing to detect embedded albumart in ID3 tags, all the files I imported today have artwork but no entries were added to the albumart table |
| [21:05:14] | Gibby (Gibby!~Gibby@204.118.10.244) has joined #mythtv | |
| [21:12:48] | stuartm: | heh yeah, the logic to actually read the albumart was removed from read() – https://github.com/MythTV/mythtv/commit/a52601a91#L2L221 |
| [21:43:43] | mrand (mrand!~mrand@ubuntu/member/mrand) has quit (Ping timeout: 252 seconds) | |
| [21:46:42] | mrand (mrand!~mrand@ubuntu/member/mrand) has joined #mythtv | |
| [21:47:24] | j-rod is now known as j-rod|afk | |
| [21:57:08] | paul-h: | stuartm: I have a couple of follow up commits that wil fix that, just been too tired to look at it the last few nights |
| [21:57:12] | knightr (knightr!~knightr@mythtv/developer/knightr) has quit (Ping timeout: 240 seconds) | |
| [21:57:41] | stuartm: | paul-h: ok, I'll keep manually fixing the db until then |
| [21:58:01] | knightr (knightr!~knightr@mythtv/developer/knightr) has joined #mythtv | |
| [21:58:09] | paul-h: | The reason I don't do the scan for images in read() is because I want to extract and cache the embedded images to speed up their display and I'm using the songid to identify the cached images which isn't yet available in read() only available later on during the file scan |
| [21:59:26] | paul-h: | The new editor allows you to rescan a file for any images to fix any you've added |
| [22:00:27] | stuartm: | sounds interesting, any plans to allow reading of the artwork for tracks not already in the DB? I'm thinking of the import files screen here where it might be nice to show the artwork before the user has decided to 'add' the file |
| [22:02:53] | stuartm: | it's not strictly necessary but I was giving some thought to adding it as an optional theme element the other night |
| [22:09:46] | paul-h: | stuartm: No there is no change to the import screen so you can only import any images as files at the moment but I'll give it some thought how we could also allow embedded images to be added as well |
| [22:09:49] | mrand (mrand!~mrand@ubuntu/member/mrand) has quit (Ping timeout: 246 seconds) | |
| [22:11:46] | mrand (mrand!~mrand@ubuntu/member/mrand) has joined #mythtv | |
| [22:13:33] | stuartm: | paul-h: sorry I think I worded that badly, I meant showing previews of the embedded albumart for the tracks alongside the other metadata (title, album, genre etc) – with the old metaio code we could read the images directly from the file even if it hadn't been imported into the DB yet because we weren't concerned about caching off the song_id |
| [22:14:50] | knightr (knightr!~knightr@mythtv/developer/knightr) has quit (Ping timeout: 276 seconds) | |
| [22:19:41] | stuartm: | if there's some mechanism for doing uncached reads, or at least reads with a temporary cache based on a temp id then we can still display those images before the track is in the DB |
| [22:20:16] | stuartm: | paul-h: don't worry about it, it can always been hacked in afterwards |
| [22:22:00] | stuartm: | it's not particularly fair of me to have an idea at the last minute |
| [22:24:47] | paul-h: | stuartm: I can see how it can be done just call getAlbumArtList(filename) to get the list of embedded images then to get the image call getAlbumArt(filename, type) to get the image no need for it to be stored in the db. Should be easy. Just got to rembember not everyone uses embedded albumart so need to also show any image files as well |
| [22:25:12] | stuartm: | paul-h: right |
| [22:27:36] | stuartm: | for importing I'm not sure how external images would work as you point at a directory which may or may not contain images from one album or a dozen different albums, the images would have to relate directly to the music files in some way e.g. "Beatles – Penny Lane.mp3.jpg" or "Abbey Road.jpg" which is possible but unlikely in a real-world scenario |
| [22:28:11] | stuartm: | I guess if you've first attached an image to the track via the metadata editor then we can display that external image |
| [22:55:07] | zombor (zombor!~zombor_@kohana/developer/zombor) has quit (Remote host closed the connection) | |
| [23:08:40] | markk (markk!~mark@cm180.omega173.maxonline.com.sg) has quit (Ping timeout: 260 seconds) | |
| [23:13:28] | natanojl (natanojl!~jonatan@c83-252-237-63.bredband.comhem.se) has quit (Ping timeout: 258 seconds) | |
| [23:20:51] | stuartm: | paul-h: the following patch would do the job under the old code, it doesn't work now that we no longer read the embedded artwork during the scan and potentially requires re-reading the tag for each file at least a second time |
| [23:21:52] | andreax (andreax!~andreaz@p57B92F30.dip.t-dialin.net) has quit (Read error: Connection reset by peer) | |
| [23:28:04] | stuartm: | well strictly speaking, a third time, I'll try and think of a slick way of doing it so that the additions to importmusic.cpp are minimal and efficient |
| [23:32:03] | abqjp (abqjp!~abqjp@97-119-171-42.albq.qwest.net) has quit (Quit: abqjp) | |
IRC Logs collected by
BeirdoBot.
Please use the above link to report any bugs.