Time Nick Message 06:23 Zeno` OK, I'm going to bisect this performance issue... somehow 06:23 Zeno` in the hopes we can push 0.4.12 out the door 06:26 est31 Zeno`: which one? 06:26 Zeno` est31, there are several. The "multi-second delay" in singleplayer seems to be the main one (the others are probably related... fingers crossed) 06:27 est31 k 06:27 Zeno` Did you have another in mind? 06:28 est31 there is #2210 06:28 ShadowBot https://github.com/minetest/minetest/issues/2210 -- getCraftRecipes implementation is very slow 06:28 est31 thats no regression though 06:28 Zeno` yeah, that was there in 0.4.11 though. 06:28 Zeno` yep 06:28 est31 so for after the release then 06:30 hmmmm Zeno`: try changing the NoDataException thrown by Connection::Receive() to a return value 06:33 Zeno` hmmmm, ok... noted. Right now I want to get some comparisons between 0.4.11 and HEAD though (because I've noticed that valgrind is much slower recently as well, although I don't know yet if this is a figment of my imagination). 06:34 Zeno` hmmmm, did the NoDataException get added recently? 06:37 hmmmm it actually hasn't 06:37 hmmmm i just noticed it sucking up 25% of wayward's serverthread time 06:37 hmmmm and another 38% was being sucked up by servicing ABMs 06:38 hmmmm btw I have optimizing ABM cals on my todo list 06:38 Zeno` ok 06:38 hmmmm lol this is funny 06:38 hmmmm i spend my entire day doing nothing but coding 06:39 Zeno` *shrug* 06:39 Zeno` nothing else to do :) 06:39 hmmmm except nothing else is getting done 06:40 hmmmm if I wasn't so ADD i would probably be able to make a healthy balance between work coding and minetest coding 06:40 hmmmm yea i'm doing my day job work at 1:40 AM :( 06:40 Zeno` hire a housemaid? :3 06:41 Zeno` she can do other stuff like make sure you bathe etc as well 06:41 hmmmm haha 06:41 hmmmm I have a gf who takes care of that sort of stuff (mostly) 06:42 Zeno` lol. "hmmmm, c'mon get outa bed and have a shower! you haven't bathed in 6 weeks now" 06:42 hmmmm more like 3 days 06:43 hmmmm ironically i blow away a lot of time i'd otherwise have to make elaborate dinners for us 06:47 Zeno` I shudder to think of a situation where that is "ironic" 06:50 Zeno` ok, I've narrowed the performance regression down to somewhere between HEAD and 3f83ca29d 06:51 Zeno` and it's real 06:51 Zeno` and huge 06:52 est31 o_O 06:52 hmmmm just curious how are you testing this 06:52 Zeno` the most professional way possible 06:53 Zeno` checkout, compile, run under valgrind, and eyeball it... lol 06:53 hmmmm i'm so paranoid that this was caused by me 06:53 Zeno` (looking a dtime) 06:55 Zeno` see... very professional methodology 06:55 Zeno` failsafe :3 07:00 Zeno` HEAD is (very roughly) half the speed of 0.4.11 07:01 Zeno` this is going to be a long afternoon 07:01 hmmmm presumably you did the next bisection step... so? 07:01 hmmmm I'm eager to hear this =] 07:01 Zeno` nah, I just wanted to make sure my environment is exactly the same between runs first 07:02 Zeno` dummy database, same location, same time of day, etc, etc, etc 07:02 Zeno` then confirm there is a difference (there is) 07:02 Zeno` and now I'll start the tedious bit 07:03 Zeno` not that those previous steps were not tedious as well :D 07:10 hmmmm ugh templates are the worst 07:10 hmmmm i don't think i've ever seen a worse approach to generics 07:11 hmmmm i feel completely dirty using them 07:25 Zeno` I just realised something. I hope I did my first step of the bisect correctly lol 07:26 Zeno` maybe I should start again now while I'm not too far into it 07:35 Zeno` *@$(82$*) 07:35 Zeno` I might have to start again: 7ad17a25f4dfc81427df54d5c855b40b4472d517 is the first bad commit 07:35 Zeno` :( 07:36 hmmmm how'd you mess it up? 07:36 Zeno` I think I forgot to call callgrind_control -i on on my first step. Modifying my script 07:37 Zeno` Modifying my script now* 07:37 Zeno` but that commit has a dtime of 100 or so 07:38 Zeno` and 0.4.11 has dtimes of 35 or so 07:38 Zeno` so it's probably narrowed down a bit. I'll do it again from scratch though 07:39 hmmmm :)! keep up the good work 07:40 hmmmm templates are a steaming pile of shit. i honestly do not care what the C++ fanboys tell me. this is horrible. I get cleaner code by removing the templates entirely 07:40 est31 did a bisect of openal last weekend, due to a crash I encountered with MT. some commits had build errors. 07:40 hmmmm it's all this extra stuff that gets added and then the language tells me that I need to start writing things in a very specific manner 07:40 est31 then I found out that these errors came from examples 07:40 est31 but only after my 3rd failed try 07:41 nrzkt hmmmm, if templates are misused yes, but when template replaced 20 common functions it's useful. 07:44 Zeno` is there are way to compile all the commits between known good and bad automatically so I can go away and sleep for a while until that's done and then just do the bisect on each compiled target nice and quick when I wake up? (only half joking) 07:45 hmmmm scripts? 07:45 Zeno` I might write one 07:45 Zeno` seems like the sort of thing I'd liek 07:45 Zeno` heh 07:45 est31 Zeno`: you can set up a bisect script 07:45 hmmmm unless your processor is really crap that won't help much since it'd take just as long to write it 07:45 est31 it only needs a return value in a specified way 07:46 hmmmm builds take around 57 seconds for me 07:46 Zeno` est31, I mean so I have, say, 90 pre-compiled executables 07:46 est31 but most times the thing that hmmmmapplies 07:46 est31 there were only 90 commits? 07:46 Zeno` hmmmm, yeah they take about that for me I guess as well... towards the end of the bisects it's much faster 07:46 hmmmm lol. if you're doing a bisect you should only need more like 7 compiles 07:46 Zeno` 90 was just a number plucked out of the air 07:47 Zeno` 90 commits doesn't take any longer than 7 usually 07:47 Zeno` oh.. compiles, yes 07:47 * Zeno` shuts up so he doesn't stuff this up a second time 07:51 Zeno` hmmmm, my point was if I had executables of all 90 commits I wouldn't have to sit here distracting myself between builds 07:51 Zeno` 57 seconds is enough for me to get distracted 07:52 est31 yea 07:52 est31 know this:) 07:52 Zeno` I could just do it(R)(TM)(C) 07:52 est31 ? 07:52 est31 I see youre building right now 07:52 Zeno` yes 08:13 twoelk wouldn't a maybe semipublic repository of builds be usefull? 08:15 hmmmm btw Zeno` did you have any comments on https://github.com/minetest/minetest/commit/0118c111e8f12602b03cee8deb4c86f9b9e28cf3 08:15 hmmmm oh nevermind that was sapier 08:19 Zeno` This is insane 08:21 Zeno` how can HEAD be twice as slow as 0.4.11 (and I can repeat this consistently) and none of the intermediate builds show much of a difference at all? There is no sudden jump at least 08:22 Zeno` geez 08:22 hmmmm erm 08:22 hmmmm i guess the problem is quite recent? 08:22 nrzkt compilation options ? 08:22 Zeno` nah, compilation options are the same 08:23 Zeno` I guess there could be more than one commit that's the problem 08:23 Zeno` and that's what's confusing my bisect results 08:27 Zeno` I guess I'll do it the hard way then :( 08:28 Zeno` first time bisect has let me down. We should abandon git. (haha j/k) 08:31 hmmmm maybe your testing methodology sux 08:32 Krock Zeno`, build fails exist 08:33 Zeno` hmmmm, it does to a certain extent. I need to rule out more variables 08:33 Zeno` Krock ? 08:34 Zeno` hmmmm, it's good for most things though. Trying to tighten it up some more now 08:34 Krock when I had problems with compiling, it just required a build from scratch but I think you do that everytime 08:34 hmmmm I suppose 08:34 hmmmm there must be a reason for this, it's only logic 08:34 Zeno` hmmmm, of course 08:35 Zeno` hmmmm, I am just wondering if it's two commits that are causing the issue. I'll eliminate all other variables (that I can) before exploring that hypothesis further though 08:35 hmmmm oh you mean like it got temporarily fixed by an earlier commit and then got re-broken in a later one? 08:35 hmmmm yeah.. 08:36 twoelk I mean that building for bisecting does take up much time, so if all builds made for such a purpose where saved to a common archive, that could get more detailed over time. I guess the only problem would be to have a standardised enviroZeno`: related to this ? https://forum.minetest.net/viewtopic.php?p=169313 08:37 twoelk gah that text was deleted, sorry was in cache 08:37 twoelk only wanted to send the link 08:38 * twoelk runs and hides 08:38 hmmmm fwiw I gave bisecting the problem a half-assed attempt 08:38 hmmmm I quit after like 3 builds though 08:41 twoelk btw, are the irc logs down? 08:42 est31 ?? 08:43 est31 http://irc.minetest.ru/minetest-dev/2015-02-03#i_4140666 08:43 Zeno` Once I eliminate every single variable I can think of (and I'm struggling to think of any more) I'll probably do some quick "hand bisecting" targeting commits that look like they could be potential offenders... not a very good way of doing things but maybe I can narrow it/them down a bit more at least. I'm kind of annoyed that performance is (apparently) back to where it was before all the crap I went through pre 0.4.11 though heh 08:43 Zeno` Note also that I profile using minimal_game, so... 08:43 hmmmm could it be the liquid transform 'fixes'? 08:43 Zeno` how minetest_game performs I have not idea 08:44 hmmmm that honestly looks like the only commits that could have such an effect 08:44 Zeno` which fixes to liquid transform? 08:44 * Zeno` looks 08:44 hmmmm the ones gregorycu was doing 08:44 hmmmm again... they only LOOK like they could have such an effect 08:44 Zeno` yeah "potential" 08:44 hmmmm relative to all the other things 08:45 Zeno` oh those commits 08:45 Zeno` yeah, they're in my list of candidates 08:45 Zeno` so are some of mine 08:45 Zeno` and some of yours :p 08:46 hmmmm I know but we're really grasping at straws 08:46 Zeno` I'll be happy if it's just narrowed down a bit more 08:46 hmmmm which commits of mine? 08:46 Zeno` I agree we're grasping at straws... but I'm running out of ideas :) 08:47 Zeno` oh they're not yours... I apologise 08:48 Krock How can I reduce the data amount which is sent by the server? I've set max_packets_per_iteration = 40 and dedicated_server_step = 0.3 but my wireless network still crashes after some minutes playing on a local server 08:48 Krock Funny thing is, there are no heavy mods activated 08:48 Zeno` I just noticed that in both of my failed bisects that something completely unrelated (I would have thought) caused slight slow downs. I attributed these as anomalies and re-ran the test before marking them as good 08:49 Zeno` (stuff related to gui and font scaling) 08:50 Zeno` Doing "statistical averaging" and significance by watching d_time is not exactly reliable (hheh) which is why I erred on the side of caution when marking things good/bad 08:51 hmmmm so do you actually feel the difference in performance between good and bad commits? 08:51 Zeno` yeah I can see it 08:52 Zeno` as in "jerkiness" 08:52 hmmmm personally, I can't 08:52 Zeno` I can't in a normal build 08:52 Zeno` but running under valgrind it's obvious 08:52 hmmmm it's like minetest has always been 'jerky' for me probably because of some odd interaction between my OS and drivers 08:52 hmmmm more like my drivers 08:52 hmmmm freaking nvidia 08:52 Zeno` I use nvidia 08:53 Zeno` under valgrind for 0.4.11 and can almost play the game 08:53 Zeno` maybe 10 fps 08:53 Zeno` HEAD is about 2-3 fps 08:53 Zeno` s/and can/I can 08:53 Zeno` I noticed this first about a week ago but kind of thought I was imagining it for some reason 08:54 Zeno` but I'm not. I've tested that about 8 times today 08:54 hmmmm i have to run it under valgrind 08:54 hmmmm even with -O0 it's too fast for me to see the effects 08:54 Zeno` I have to as well otherwise I just get 60FPS heh 08:54 Zeno` same 08:54 Zeno` which is why I'm using valgrind... to slow it down in (what I hope is) a kind of consistent way 08:54 Zeno` adding a sleep won't work 08:54 hmmmm problem is I get incorrect path_user when I run under valgrind 08:54 Zeno` (obviously) 08:55 hmmmm I added that freebsd code too :( 08:55 Zeno` wonder why 08:55 hmmmm how does Valgrind lie to the application about its executable path? 08:55 Zeno` can I PM? 08:55 hmmmm sure 09:00 twoelk Zeno`: In the link I messed up sending, TenPlus1 says turning the hud on and off with F1 makes a great difference fps-wise 09:01 Zeno` twoelk, I saw that 09:01 Zeno` and it makes .... 09:02 Zeno` I just noticed that in both of my failed bisects that something completely unrelated (I would have thought) caused slight slow downs. I attributed these as anomalies and re-ran the test before marking them as good 09:02 Zeno` more plausible ;) 09:02 Zeno` because both of the commits I noticed affect the HUD 09:02 Zeno` bbiab 09:03 Zeno` I'll ask 10+1 for some more info later, most likely 09:03 kilbith can't reproduce that issue 09:10 Zeno` neither can I, so maybe just a coincidence but I'm trying to keep an open mind atm 09:10 Zeno` because I'm running out of ideas :) 09:11 kilbith some people are full of weird issues 09:11 kilbith murphy's law or so 09:11 Zeno` I have the performance issue... just that hud or hud seems to make no difference for me 09:11 kilbith ditto 09:11 Zeno` I don't think.. It might, I have to add more to my tests 09:12 kilbith F1 on/off is strictly FPS constant 09:13 Zeno` it does add about 30ms to d_time 09:13 Zeno` wouldn't think that'd make a difference, but maybe it does in some configs 09:14 Zeno` you're not going to see 30ms make a difference under normal circumstances though, of course ;) 09:15 kilbith it'd be not negligable in a FPS game... not here 09:18 rubenwardy Would be hilarious to see average FPS against commit number. 09:33 Zeno` kilbith, I mean you would not normally notice it, not that it's negligible ;) 09:34 Zeno` rubenwardy, profile 0.4.10 and 0.4.11 :D 09:35 Zeno` kilbith, you know me better than that :p 09:35 Zeno` I didn't increase avg fps from 20 to 60 just for the heck of it heh 09:36 Zeno` anyway, test environment is as "clean" as I can get it now 09:36 Zeno` trying to bisect again 09:36 kilbith i was not implying that you thought it was negligible 09:37 kilbith just said that 30ms of diff. is derisory on a voxel game 09:38 Zeno` you are, of course, 110% correct :D 09:38 Zeno` I just realised there may be an easier way to track this down 09:38 kilbith and that'd make sense only on furious FPS game 09:38 Zeno` 30ms is a HUGE amount of time btw 09:40 Zeno` dunno why I didn't think of this alternative way before instead of wasting time bisecting 09:40 rubenwardy Running at 60fps would give 17ms, so 30 is a lot. 09:40 Zeno` rubenwardy, yep 09:42 Zeno` but this 30ms is in, hmmm, "altered conditions" (so I can actually see things happening). Under "real" it's a 25% slowdown on a function that's very fast to begin with, but 25% is 25% 09:42 Zeno` not 25% overall slowdown 09:42 Zeno` although it could be... it's complex :( 09:43 Zeno` whatever the case it's not acceptable or desirable 09:45 Zeno` this also could be a side-effect of things being faster in general 09:45 Zeno` which was the source of another hard to find "bug" 09:45 rubenwardy Slow downs because it is faster? O_o 09:46 Zeno` rubenwardy, in the other case it was a mem-leak that really never showed up until things were faster 09:46 Zeno` but yeah... that "auto ranging thing".... 09:47 rubenwardy Well, good luck. 09:47 Zeno` maybe it's misbehaving now 09:47 Zeno` I think we'll need it because atm this is causing people to tear their hear out :D 09:47 Zeno` hair 09:47 rubenwardy If Minetest was an iceberg, I've barely even got a milimetre into it from the top, let alone underneath the water. 09:50 Zeno` when I disallow the game changing v_range with it's ... not sure what to call it... auto optimise view range? ... things are a lot less different between 0.4.11 and head 10:15 twoelk maybe a fixed viewrange frees the engine of having to decide what to display. Like when it flickers between showing and not showing 10:44 Zeno` well, it does... 10:44 rubenwardy Solution: 10:45 Zeno` I'm becoming more convinced that the "auto range" thing is the actual issue 10:45 rubenwardy OPTIMISE!!! 10:45 Zeno` but what "auto range" does is always increase the v_range until the game loop cannot cope and then slowly decreases until it can again 10:45 Zeno` and then off it goes again 10:46 rubenwardy Lol 10:47 rubenwardy What would a better solution be? 10:51 Zeno` I'm not really sure 12:08 gregorycu Is it just me, or are there a lot of new bugs out of nowhere 12:17 gregorycu http://irc.minetest.ru/minetest-dev/2014-12-22#i_4073950 13:06 Zeno` this is quite mind boggling 13:09 celeron55 the range adjuster is intentionally as responsive as possible; it was causing problems when it was too unresponsive 13:10 celeron55 i guess it could be tuned to be not that responsive now that we have the mesh loading slowness problem; altough it's only a problem with dedicated GPUs 13:13 celeron55 someone with the issue could see whether it's best solved by tweaking min_time_per_range or the wanted_range_change dampening multiplier in camera.cpp 13:14 Zeno` no, no 13:14 Zeno` it's not that at all 13:14 celeron55 altough now that i think of it, both of those are actually unsuitable 13:15 celeron55 there should be a measurement window of a couple of frames from which always the fastest frame is taken 13:15 Zeno` yeah, that needs tweaking and stuff but this is not the source of the performance regression 13:15 Zeno` and I need to compile and test for a 5th time to make sure I'm not imagining things 13:15 Zeno` because the issue is quite... crazy 13:15 celeron55 the issue with the range adjuster is that it always masks issues for people new to minetest 13:16 celeron55 and then they waste time thinking about it instead of their real problem 13:19 Zeno` well, the only reason I brought it up was because... I can't remember why I brought it up 13:19 Zeno` but it's not the issue 13:23 Zeno` ok, I am certain of the commit 13:24 Zeno` I've checked it 4 times now 13:24 Zeno` I even reverted it on top of HEAD instead of checking it out to be quadruple sure 13:24 Zeno` https://github.com/minetest/minetest/commit/38bd9e93a252cb2dd5ace6b0132514edff38b504 13:24 Zeno` but... 13:25 Zeno` why? 13:25 Zeno` it *seems* to be related to src/clientmap.cpp line 193 being commented out 13:26 Zeno` I wonder if that being in a lock even if it's unused changes something 13:26 Zeno` I'm truly at a loss :( 13:27 Zeno` that commit, for a reason that I cannot work out, adds 11% work to the update/draw/render loop 13:27 Zeno` (for the client) 13:32 SudoAptGetPlay Quick question : can we still register new nodes after all mods are loaded ? 13:33 SudoAptGetPlay nvm I will try a different approach 13:40 Zeno` https://www.dropbox.com/s/5wj5xqbvnm52stw/perf_reg.tar.gz?dl=0 13:41 * Zeno` panics 13:43 Zeno` 8 hours of bisecting, checking valgrind logs, stablising my test env, reverting, checking, double checking, and I end up with a commit that's the cause and I cannot understand why 13:43 Zeno` this is is tragedy 13:43 * Zeno` might need to have a shower or something else just as drastic 13:43 nrzkt bisect the commit himself ? 13:43 nrzkt itself* 13:45 Zeno` my head hurts. /me wanders off in search of a painkiller 13:47 Zeno` HUD is not being drawn twice is it? 13:48 Zeno` hmm, no 13:49 Zeno` anyway, look at the profiles... the only apparently relevant file (for this) is clientmap.cpp 13:50 Zeno` and sfa has changed :/ 14:16 alket hi 14:16 alket can anyone help me setup a minetest server ? , I will give you ssh access 14:16 alket I already installed 0.4.10 through PPA 14:16 kilbith all the documentation on wiki / forum already 14:17 SudoAptGetPlay 4.10 is quite outdated 14:17 alket yes but it doesnt work for me 14:17 kilbith ask on #minetest please 14:30 Zeno` Wayward_One, can you do a test for me? 14:31 Zeno` Wayward_One, can you compile this https://github.com/Zeno-/minetest/commit/02d7efefdb852b256fb2a349b95b629df03f9a49 and see if it affects your performance issues? 14:31 Wayward_One sure, one sec, finishing a callgrind session 14:32 Zeno` you're ok with getting and applying the patch? 14:32 Wayward_One yep :) 14:32 Zeno` good, I can pass out then 14:34 Wayward_One lol 17:46 Niebieski Hey guys, I want to contribute, is there something I can do ? 17:49 sfan5 Niebieski: http://dev.minetest.net/How_to_start_contributing 17:50 sfan5 that page is a little empty 17:50 sfan5 so ask if you want to know more 17:50 Niebieski Alright. 17:51 acerspyro You could develop that page ^.^ 18:37 Niebieski I've read the page, and decided to take a look at main.cpp and I can't understand most of things. 18:45 Niebieski Like why we need many time getters. 18:59 est31 what are the blocking issues for 0.4.12 now. can I help 19:00 luizrpgluiz 0.4.12? That fast, which will be the new? 19:02 rubenwardy The main blocker is drop in FPS. 19:02 rubenwardy Probably due to the algorithm which adjusts the view range 19:02 rubenwardy It's being worked lon 19:02 est31 by Zeno 19:03 rubenwardy Yes 19:04 VanessaE there are other bugs that really need to be fixed before 0.4.12 goes out, imho 19:04 VanessaE anything that was a blocker for 0.4.10 or 0.4.11, but which got unmarked as such and was never fixed 19:04 VanessaE and anything marked as "high priority" 19:08 est31 luizrpgluiz: https://github.com/minetest/minetest/compare/3f83ca2...master 19:08 est31 for a detailed list 19:09 Calinou rubenwardy, we could try disabling range tuner entirely 19:09 Calinou we could have a setting for this (detects min/max range, if they are equal, disable range tuner) 19:09 Calinou to see if it causes FPS losses/drops 19:09 Calinou VanessaE, there is a bug with wield item rendering on Windows, still present 19:10 rubenwardy It is not a vital feature, although it is good. 19:10 Calinou yeah, we could do without it, let users tweak view range in GUI instead 19:10 Calinou the default would be 60 or so 19:43 luizrpgluiz will leave the faster engine? 23:33 est31 Tesseract: do you already have something I can rebase onto?