Dwarf Fortress Bug Tracker - Dwarf Fortress
View Issue Details
IDProjectCategoryView StatusDate SubmittedLast Update
0004207Dwarf FortressDwarf Mode -- Environmentpublic2011-03-12 14:492012-03-30 10:21
ReporterSolra Bizna 
Assigned ToToady One 
PriorityhighSeveritymajorReproducibilityalways
StatusresolvedResolutionfixed 
PlatformLinuxOSDebianOS VersionSqueeze
Product Version0.31.18 
Target VersionFixed in Version0.34.01 
Summary0004207: Inescapable, inevitable, intolerable lag
DescriptionThis has killed dozens of my fortresses before their time. The game becomes intolerably slow when the tickrate drops below about 40 for me, but I've had it drop as low as 6 due to this problem. Dwarf population, animal population, spatter quantity, fluid activity, item quantity, temperature dynamics, and invasions do not substantially affect it; even if I kill all my dwarfs and animals, my tickrate remains quite low. My tickrate is more than adequate until this bug is triggered.
Steps To ReproduceThis is how most of my forts progress:
* Dig in near the wagon.
* Build communal sleeping and dining space for my dwarfs.
* As quickly as possible, make enough stockpile space to store the contents of the wagon.
* Secure the entrance to my fort with many traps, or at least make it sealable.
(At this point, my framerate is fine. If I wait forever, so dozens of migrants come and my population nears 200, my framerate REMAINS fine.)
* Dig out individual living quarters (6 tiles) for my dwarves. This causes my framerate to precipitously drop. Even digging out quarters for 30 dwarves can trigger a framerate drop into the unplayable range.
This also happens if I replace the word "dig" in the last step with the word "build."
Additional InformationThe framerate death can be put off worth approximately 10 dwarf quarters by putting doors EVERYWHERE, but in the end all of my fortresses get abandoned before they get really interesting because of this problem.
Digging out a large contiguous area also triggers this problem, but only after the fort has established itself. I have not been able to reproduce this framerate drop by making a fortress whose sole purpose is to dig out entire Z-levels.
I don't know if it occurred previous to 0.31.12 or so. I am tagging this 0.31.18 because this is the version I did my most recent test game in. I can upload a save where this problem has just begun to show itself. I haven't yet confirmed if the lag can be reversed by un-digging/un-building, I'm going to do that later today.
TagsNo tags attached.
Relationships
related to 0003942resolved Toady One Dwarves owning broken clothing. Clothes don't rot, ANNIHILATES FPS. 
related to 0003651resolved Toady One Ghost appearing/disappearing causes a massive slowdown 
Attached Files
Issue History
Date ModifiedUsernameFieldChange
2011-03-12 14:49Solra BiznaNew Issue
2011-03-12 14:50Solra BiznaIssue Monitored: Solra Bizna
2011-03-12 15:52Granite26Note Added: 0016171
2011-03-12 15:52Granite26Issue Monitored: Granite26
2011-03-12 15:59dravusNote Added: 0016172
2011-03-12 16:39Solra BiznaNote Added: 0016173
2011-03-13 22:09FootkerchiefNote Added: 0016227
2011-03-13 23:49thvazNote Added: 0016229
2011-03-14 00:21AbuDhabiNote Added: 0016230
2011-03-14 00:21AbuDhabiIssue Monitored: AbuDhabi
2011-03-14 05:38AbuDhabiNote Edited: 0016230bug_revision_view_page.php?bugnote_id=0016230#r6051
2011-03-14 06:20AbuDhabiNote Edited: 0016230bug_revision_view_page.php?bugnote_id=0016230#r6055
2011-03-14 07:10AbuDhabiNote Edited: 0016230bug_revision_view_page.php?bugnote_id=0016230#r6056
2011-03-14 09:31AbuDhabiNote Edited: 0016230bug_revision_view_page.php?bugnote_id=0016230#r6057
2011-03-14 14:56Solra BiznaNote Added: 0016247
2011-03-14 15:12dravusNote Added: 0016248
2011-03-16 01:28AbuDhabiNote Added: 0016289
2011-03-16 11:39KogutNote Added: 0016302
2011-03-16 12:06FootkerchiefRelationship addedrelated to 0003942
2011-03-16 12:06FootkerchiefRelationship addedrelated to 0003651
2011-03-16 15:32Malibu StaceyNote Added: 0016303
2011-03-16 17:04FootkerchiefNote Added: 0016304
2011-03-16 17:39Malibu StaceyNote Added: 0016305
2011-03-16 18:20FootkerchiefNote Added: 0016310
2011-03-16 21:11FootkerchiefNote Added: 0016311
2011-03-16 21:59Solra BiznaNote Added: 0016313
2011-03-16 23:29Solra BiznaNote Added: 0016314
2011-03-16 23:32Solra BiznaNote Edited: 0016314bug_revision_view_page.php?bugnote_id=0016314#r6089
2011-03-17 01:05Solra BiznaNote Edited: 0016314bug_revision_view_page.php?bugnote_id=0016314#r6090
2011-03-17 05:52Granite26Note Added: 0016323
2011-03-17 07:46FootkerchiefNote Added: 0016329
2011-03-17 07:46FootkerchiefNote Edited: 0016329bug_revision_view_page.php?bugnote_id=0016329#r6092
2011-03-17 09:07FootkerchiefNote Added: 0016334
2011-03-17 09:39FootkerchiefNote Edited: 0016334bug_revision_view_page.php?bugnote_id=0016334#r6100
2011-03-17 17:01Solra BiznaNote Added: 0016342
2011-03-17 17:01Solra BiznaNote Edited: 0016342bug_revision_view_page.php?bugnote_id=0016342#r6108
2011-03-30 13:27FootkerchiefNote Added: 0016811
2011-05-13 00:02Solra BiznaNote Added: 0017710
2011-05-13 00:02Solra BiznaNote Edited: 0017710bug_revision_view_page.php?bugnote_id=0017710#r6586
2011-05-13 05:53agNote Added: 0017711
2011-05-13 10:33kwielandNote Added: 0017714
2011-05-13 13:09kwielandNote Edited: 0017714bug_revision_view_page.php?bugnote_id=0017714#r6588
2011-05-13 21:41kwielandNote Edited: 0017714bug_revision_view_page.php?bugnote_id=0017714#r6589
2011-05-14 00:39Solra BiznaNote Added: 0017718
2011-05-14 03:29Solra BiznaNote Edited: 0017718bug_revision_view_page.php?bugnote_id=0017718#r6591
2011-05-14 03:58Solra BiznaNote Edited: 0017718bug_revision_view_page.php?bugnote_id=0017718#r6592
2011-05-14 11:36agNote Added: 0017727
2011-05-15 07:17agNote Added: 0017733
2011-05-15 10:53Solra BiznaNote Added: 0017740
2011-05-15 10:57kwielandNote Added: 0017741
2011-05-16 02:32agNote Added: 0017751
2011-05-17 17:36Hieronymous AlloyIssue Monitored: Hieronymous Alloy
2011-05-18 09:16Solra BiznaNote Added: 0017774
2011-05-18 09:37agNote Added: 0017775
2011-05-18 19:07kwielandNote Added: 0017778
2011-05-18 19:08kwielandNote Edited: 0017778bug_revision_view_page.php?bugnote_id=0017778#r6633
2011-05-19 03:21Solra BiznaNote Added: 0017781
2011-05-19 04:21agNote Added: 0017782
2011-05-19 05:45Solra BiznaNote Added: 0017783
2011-05-19 06:23agNote Added: 0017785
2011-05-19 07:57Solra BiznaNote Added: 0017786
2011-05-19 08:53agNote Added: 0017787
2011-05-19 08:56agNote Edited: 0017787bug_revision_view_page.php?bugnote_id=0017787#r6635
2011-05-20 13:40Solra BiznaNote Added: 0017805
2011-05-20 14:44Solra BiznaNote Edited: 0017805bug_revision_view_page.php?bugnote_id=0017805#r6650
2011-05-21 17:28kwielandNote Added: 0017817
2011-05-28 14:35Hieronymous AlloyNote Added: 0017885
2011-05-28 23:23agNote Added: 0017893
2011-05-28 23:37agNote Edited: 0017893bug_revision_view_page.php?bugnote_id=0017893#r6679
2011-07-08 02:15Solra BiznaNote Added: 0018154
2011-07-08 02:37Solra BiznaNote Edited: 0018154bug_revision_view_page.php?bugnote_id=0018154#r6785
2011-07-08 08:33kwielandNote Added: 0018155
2011-07-08 23:49Solra BiznaNote Added: 0018165
2011-07-09 03:53BeeskeeIssue Monitored: Beeskee
2011-07-09 10:22rofl0rNote Added: 0018179
2011-07-10 06:22rofl0rNote Added: 0018193
2011-07-10 07:22DwarfuIssue Monitored: rofl0r
2011-07-10 07:22DwarfuNote View State: 0018179: private
2011-07-10 07:23DwarfuNote View State: 0018193: private
2011-07-10 07:49rofl0rNote View State: 0018179: public
2011-07-10 07:49rofl0rNote View State: 0018193: public
2011-07-10 10:17DwarfuNote Deleted: 0018179
2011-07-10 10:17DwarfuNote Deleted: 0018193
2011-07-11 00:49Solra BiznaNote Added: 0018197
2011-07-11 00:50Solra BiznaNote Edited: 0018197bug_revision_view_page.php?bugnote_id=0018197#r6803
2011-07-11 10:16kwielandNote Added: 0018203
2011-07-12 02:50Solra BiznaNote Added: 0018207
2011-07-27 05:50Solra BiznaNote Added: 0018321
2012-02-20 18:39Solra BiznaNote Added: 0020308
2012-02-20 19:12FootkerchiefNote Added: 0020315
2012-02-20 19:12FootkerchiefStatusnew => resolved
2012-02-20 19:12FootkerchiefFixed in Version => 0.34.01
2012-02-20 19:12FootkerchiefResolutionopen => fixed
2012-02-20 19:12FootkerchiefAssigned To => Toady One
2012-02-21 09:12Granite26Issue End Monitor: Granite26
2012-03-30 10:21AbuDhabiIssue End Monitor: AbuDhabi

Notes
(0016171)
Granite26   
2011-03-12 15:52   
I can confirm this...
(0016172)
dravus   
2011-03-12 15:59   
I don't get it this bad but I still get lag spikes here and there

it's mostly to do with CPU power more than anything......my FPs remains around the 20-30 mark on my 2ghz Athlon 64 3200+ (32bit mode)

those with stronger CPU's have less of an issue (my friend started playing with his 3ghz core2duo....haven't heard any fps complaints to date)

if anything it could be down to your CPU
(0016173)
Solra Bizna   
2011-03-12 16:39   
My CPU is a quad 3.2GHz Phenom II, and I have DDR3-1066 RAM.
In my latest test fort, I had built my apartment complex above the ground connected by a single slender support. Pulling the support (with no casualties) did not provide an increase in tickrate, though it did result in a humorous amount of platinum dust everywhere. (...Yes, I built it out of solid platinum.)
I did note a momentary boost to my tickrate when I ordered everyone to safety, but it's probably the tickrate-reported-wrong-for-first-few-seconds-after-game-is-unpaused bug.
(0016227)
Footkerchief   
2011-03-13 22:09   
Reminder sent to: Solra Bizna

If there's an abrupt transition from good FPS to bad FPS, it would be helpful to upload a save where that transition occurs, i.e. the save starts with good FPS, then the dwarves complete a dig designation and the framerate drops. You can upload to http://dffd.wimbli.com/ [^]
(0016229)
thvaz   
2011-03-13 23:49   
Very informative summary.
(0016230)
AbuDhabi   
2011-03-14 00:21   
(edited on: 2011-03-14 09:31)
Something like this does seem to happen to me too.

EDIT: I am trying to reproduce this problem. I have embarked on a small world with only dwarves left alive, and have made rudimentary quarters for all my dwarves. I have made several stockpiles, and have dug down to the caverns. I am trading with the dwarves various stuff in exchange for mugs.

So far, no problems with framerate. My population is restricted at 30, so migration stops when the numbers grow to 45 or so (currently at 47; I expect no further migrants).

EDIT2: Have dug deeper, uncovered all three levels of caverns. I have installed a small danger room for one military dwarf to train. My workshops are outside. A few dozen wildlife specimens have been slain. Framerate stays at 100.

EDIT3: Game is starting to slow down at the end of the third year. FPS hovers around 90.

EDIT4: It is the spring of the 5th year, and framerate is still hovering between 90 and 100. Solra, how much time usually passes until you experience this lag? I have a tentative theory that it's something to do with other civilizations, since I can't seem to reproduce it here.

Last save: http://dffd.wimbli.com/file.php?id=3964 [^]
(0016247)
Solra Bizna   
2011-03-14 14:56   
Usually it bites me before the end of the third year. Regarding other civilizations, the two times I've tried (and failed) to reproduce it by digging out entire Z-levels have both been on tiny worlds with very few civilizations.
I'm just beginning a normal fort now. When I reach the point where I'm digging out quarters, I'll save (and back up) after designating but before unpausing, then see if the framerate drops just from waiting. Unlike other forts I've made, this one will have invaders off.
(0016248)
dravus   
2011-03-14 15:12   
#In my latest test fort, I had built my apartment complex above the ground connected by a single slender support. Pulling the support (with no casualties) did not provide an increase in tickrate, though it did result in a humorous amount of platinum dust everywhere. (...Yes, I built it out of solid platinum.)#

that sounds like you might have pathing issues.....maybe....don't take my word for it on that
I tend to get pathing related FPS drops myself
(0016289)
AbuDhabi   
2011-03-16 01:28   
Uploading that save would probably help a lot, Solra.
(0016302)
Kogut   
2011-03-16 11:39   
0003942 ? Ghosts?
(0016303)
Malibu Stacey   
2011-03-16 15:32   
duplicate of 0003942
(0016304)
Footkerchief   
2011-03-16 17:04   
0003942 and this report both lack any concrete evidence, so it's hard to know if this is a duplicate. This report seems to be describing an abrupt transition to low FPS, which seems more in line with 0003651.
(0016305)
Malibu Stacey   
2011-03-16 17:39   
Um Foot unless I can't read properly the actual report of 0003942 has steps to reproduce & "concrete evidence".
(0016310)
Footkerchief   
2011-03-16 18:20   
"Concrete evidence" = a save demonstrating the problem.
(0016311)
Footkerchief   
2011-03-16 21:11   
Reminder sent to: Granite26, Solra Bizna

This problem can't be fixed, nor can the report be properly categorized, without a save demonstrating the problem. Please upload one to http://dffd.wimbli.com/ [^]
(0016313)
Solra Bizna   
2011-03-16 21:59   
I'm still working on a save. This is separate from the ghost lag, that was a fort that I was making to test this issue and I hit a different issue instead.
(0016314)
Solra Bizna   
2011-03-16 23:29   
(edited on: 2011-03-17 01:05)
http://virus.tejat.net/a004_200_trueprebuild.tar.bz2 [^]

Turn off INVADERS and ARTIFACTS, set the population cap to 1 (so migrants won't come), break up the party (so the miner will work) and slaughter the ducks (so a ducksplosion is avoided). The miner will dig an excessively large apartment complex. I ran the game a while before digging and my uncapped tickrate oscillated between 170 and 210. If he only digs two apartment levels, the tickrate does not change significantly, but if he digs all the levels designated in that save, the tickrate falls to 100-140 (fairly abruptly after being constant for a while). At least, I think it does... I had a ducksplosion around the same time as the tickrate fell, but it didn't rise back up once all the ducks were turned into duck skulls. I'm digging more Z-levels of apartment to see if the framerate goes down further.

Edit: Digging approximately twice the number of apartments brought my tickrate down to 80-95. I think that rules out ducks as the cause. My dwarfs' clothes have been fairly worn this entire time, ruling that out. Absolutely no sapient creatures have died at this fort, so ghosts are definitely not the cause.

Now to cathartically flood my fort.
(0016323)
Granite26   
2011-03-17 05:52   
I think it's due to too many items bring present(mostly stones). In my case, it was due to the pc overheating and the pagefile thrashing. Eventually the whole system just shut down.

Basically, you can unpause the game and it'll run ok for a while, with a high fps, but as stuff gets loaded into memory (reloaded?) it'll start to slow way down.

Unless there's another explanation for leaving the pc on overnight, unpausing the game and having great fps for a few seconds, and then it dropping. (Not an artifact, either, dwarves and flows move super fast at first)

Could upload a save, but I don't have a clean one. (too much crap going on, water and magma flows, etc)
(0016329)
Footkerchief   
2011-03-17 07:46   
Reminder sent to: Solra Bizna

I'm getting a "source file could not be read" error when I try to download your save. As previously requested, please upload to http://dffd.wimbli.com/ [^]
(0016334)
Footkerchief   
2011-03-17 09:07   
(edited on: 2011-03-17 09:39)
Okay, I managed to download it now, and I'm uploading it to DFFD.

Uploaded Solra Bizna's save: http://dffd.wimbli.com/file.php?id=3982 [^]
(0016342)
Solra Bizna   
2011-03-17 17:01   
That's a scary error for my server to be throwing. I wish I had more details.

Item quantity was the first thing we ruled out way back when we first started experiencing this problem; it still happens even if we dig out only soil layers and never touch a single boulder. As for computer stress, this computer has cooling adequate for twice its TDP, high-quality AC input, and five times as much RAM as DF requires at its peak. The latest theory among me and my buds is that this lag has something to do with vermin spawning, or plant growth, or some such related task.

I think this is also related to the horrific lag one experiences if one embarks in a very large area.
(0016811)
Footkerchief   
2011-03-30 13:27   
Reminder sent to: Solra Bizna

Does your save still exhibit the problem in 0.31.25?
(0017710)
Solra Bizna   
2011-05-13 00:02   
Sorry about the delayed reaction.

Repeating the test with 0.31.25 and a roughly 7 % faster CPU still results in a tickrate drop, though it begins a little later and falls a little more gradually. I'm currently investigating whether the slowdown happens in a world with no vermin.
(0017711)
ag   
2011-05-13 05:53   
Lately I've been profiling the linux version using oprofile, and have identified a hot spot in the flag checks done by the flow engine. Basically, every frame it walks all 16x16 tile blocks (>10000 of them even on a 3x3 embark), and checks if it has anything to do. The trouble is that even if this check is hacked to use 5 hand-written machine instructions instead of a complicated function call, it still causes two cache and TLB misses for every block. On my old P4 this amounts to these 5 instructions using at least 15% of all run time of an established 3x3 fortress (more on a fresh embark). Not much, but certainly wasteful.
(0017714)
kwieland   
2011-05-13 10:33   
(edited on: 2011-05-13 21:41)
I notice this as well. I also think that it doesn't have anything to do with clothes or the total number of items. I also noticed the largest hit when I started mining out large single z level areas.

My current thought is that it has to do with something in the background (Vermin, dead pets trying to claim owners, plants growing, who knows!). I usually use the trick here: http://df.magmawiki.com/index.php/DF2010_Talk:Trading#Traders_taking_forever_to_load_up [^] . For a new game, when you hold down the mouse the FPS hovers at the max. However, I noticed later in the game when the "normal" FPS starts to drop (say 40), I've seen this at 20! And all I'm doing is designating areas! Something in the background is using up a lot of CPU!

I'll see if I can nail it down better. I am going to not mine anything, all aboveground constructions. That should make it easy to see if the number of dwarves is causing the lag.
(0017718)
Solra Bizna   
2011-05-14 00:39   
(edited on: 2011-05-14 03:58)
Try making your aboveground constructions horizontal, without using multiple floors. Avoid ceilings where possible, too. When I tried a construction-heavy fort, I built vertically and still experienced the slowdown.

Edit: My vermin-free fort still experienced a downward slide associated with digging. Digging out a 27x30 area for my catapults to fire through dropped my tickrate from 80 to 50; and the only reason it was as high as 80 is that temperature and weather simulation is off. This doesn't completely rule out vermin spawning as a cause, but it makes it seem less likely.

Edit 2: I seem to have spoken too soon, after the digging process was complete the tickrate went back up to 80. I'll keep digging and digging and we'll see...
(0017727)
ag   
2011-05-14 11:36   
After playing for some time with oprofile and the above map save, I can see that during the time it takes for that single dwarf to dig out what's designated + the same amount, the plant population grows from around 4000 to 14000. The plant management overhead also grows from 5 to 15%.

Since stuff is still running fast, the flow engine flag check overhead is around 30-40%.

I have weather and temperature disabled. I didn't notice any abrupt slowdown; maybe my computer is already too slow or maybe it depends on the exact size of CPU caches or something.
(0017733)
ag   
2011-05-15 07:17   
Another bit of profiling results: when you're trying to reproduce a bug using one miner, the other dwarves have nothing to do - and when they have nothing to do they talk and party, and accumulate a history of a few hundred 'talked to whatever' thoughts per dwarf. Since every thought has to be checked every frame in case it is old enough to be deleted, this also causes additional load that reached 8% in the worst case during my experiments.
(0017740)
Solra Bizna   
2011-05-15 10:53   
That would explain the wide variance in framerate I usually see. I tend to alternate between having a lot of idle dwarves and having very few.
(0017741)
kwieland   
2011-05-15 10:57   
Wow, ag, not simple at all, is it! Have to keep the dwarves busy, but not making stuff. Maybe operating screw pumps tied to nothing?

Here is a partial report about my aboveground fort. pocket world, but all species around (besides kobolds - see other bug about them). Started off but forgot an ax. Generated a lot of wealth harvesting plants and cooking seeds/booze. Three game years in, <50 dwarves (no limit in init), no digging period and only 1 z level to build beds and a table/chair. FPS is already mid 80s. That is amazing. I didn't embark with any stone, so I couldn't make any mechanisms for traps. I just got ambushed and am heading for a spiral. We shall see if I need to embark again!

I just passed 80 FPS on a 20+ year fort that followed a similar path outlined in the summary above. Now it has 170 dwarves (though many are children - I've got one couple with 28 kids; 17 have grown to adults already!) and the FPS is pretty stable around mid 20s. This one I noticed a pretty big drop in FPS when I made two different paths down to the magma sea. Before that it was ~100s, after in the 80s. I explained it at the time as a pathing hit. I can block off one of the paths and see if the FPS changes at all.
(0017751)
ag   
2011-05-16 02:32   
All these hot spots are reads from memory, so they are highly dependent on the CPU cache performance and memory speed. For instance, the P4 I use only has 2MB cache, so it is pretty much full from the start; if you have more, the initial working set might actually fit, so you'll have a moment when stuff suddenly becomes slower. Maybe I should make a profiling kit with a how-to, or something (linux-only, obviously :).
(0017774)
Solra Bizna   
2011-05-18 09:16   
Played a test fort with no vermin or underground plants, 4x4 embark, roughly 130 Z-level area. I was going strong at 100fps for the first few years, when suddenly it dipped to 60 and then recovered to around 80, where it has since remained. The drop happened while I was digging out a 25x25 pit on the surface. I was also digging a ~20x15 area at roughly floor -90 around my main staircase. During the drop, no migrants came, no new animals were born, and the plant population was in check. In terms of dug area, what I had at the time was pretty typical of where I'm at when the framerate starts to go down.
(0017775)
ag   
2011-05-18 09:37   
Here are my scripts and readme: https://github.com/angavrilov/dfprofile [^]

If it works on your system, you could try to collect some data from saves before and after the drop, and try to see what are the differences.
(0017778)
kwieland   
2011-05-18 19:07   
(edited on: 2011-05-18 19:08)
I was thinking to test the lag another way. I abandoned my well established fort with a FPS of 17. I then reclaimed the fort. (It took a good minute to reclaim, by the way, be patient here)

Reclaiming was worthless. First, all 10,000+ items were now spread everywhere. Second, I had over 18 HFS running around "ambushing" my dwarfs. (They were previously contained in the caverns).

So, if you want to try that, first make sure all the HFS is cleared out of the caverns. Second, make sure you eliminate everything you can - seeds, rocks, etc!

Oh well. The "running" FPS was still around 45, though, if that helps.
(0017781)
Solra Bizna   
2011-05-19 03:21   
"oprofile --no-vmlinux --start" resets my CPU. Pretty spectacular. My guess is some incompatibility with VirtualBox. (I fiddled with perf_event_paranoid to no avail.)

I'm going to continue digging on my latest test fort. My eventual goal will be to break into the "candy store" and see if 1) it causes a large drop in tickrate and 2) I can successfully seal off a portion of it. Long before that happens, I expect to see this bug worsen greatly.

Just in case something changes and I can get profiling data, I'm making copies of this save at intervals. I should be able to go back and profile them later.

For the record, my (now six-core) CPU has 6MB of shared cache and 512KB of per-core cache.
(0017782)
ag   
2011-05-19 04:21   
Well, oprofile uses hardware profiling counters in the CPU, so if virtualbox doesn't intercept access to them from inside the VM, it is quite possible that the outside OS kernel gets an unexpected interrupt and dies. You can try enabling the "hardware virtualization" option in VirtualBox, or switching to timer mode:

$ opcontrol --deinit
$ modprobe oprofile timer=1

It does an order of magnitude less measurements per second than the default mode, though.
(0017783)
Solra Bizna   
2011-05-19 05:45   
DF is running on the host, not the guest. I tried with timer mode, and it didn't reset, but the closest I got opreport to outputting something useful was:

Overflow stats not available
error: no sample files found: profile specification too strict ?

It looks like it's only sampling root's and kern's processes. I couldn't figure out how to get it to sample my user's processes.
(0017785)
ag   
2011-05-19 06:23   
Hm, strange, did you do the --start line after modprobe?.. Or --dump before opreport? Or specify the full path to the game executable/cd to its directory?

I guess I should add all this to the readme. Note that I didn't know about the timer option myself before searching for it. Btw, does it still crash if no vm is running (and perhaps without the kernel module loaded at all)?
(0017786)
Solra Bizna   
2011-05-19 07:57   
> did you do the --start line after modprobe?.. Or --dump before opreport? Or
> specify the full path to the game executable/cd to its directory?
All of the above.

> Btw, does it still crash if no vm is running (and perhaps without the kernel
> module loaded at all)?
Next time I reboot, I'll be sure to check that before starting the VMs.
(0017787)
ag   
2011-05-19 08:53   
(edited on: 2011-05-19 08:56)
Very strange... I tried the timer mode myself, and everything worked as usual. Does opreport output anything if called without any arguments? If the game was on pause, it might have produced no data because all SDL and OpenGL rendering code seems to be in libgraphics.so. Also, opreport doesn't actually check if the path is correct; it seems to simply print whatever matches in its data.

I've updated the scripts and readme a bit.
(0017805)
Solra Bizna   
2011-05-20 13:40   
(edited on: 2011-05-20 14:44)
(Sorry for the delay, my network is having trouble with the bay12games.com domain.)

I looked (at the time) in oprofile's state dir, and only saw states for the root and kern users.

It's going to be several days before I can work on this again, I've had a sudden increase in workload.

Edit: And a just as sudden reprieve. The only way I can currently get to my DF machine is virtualized, so it's useless for profiling purposes, but I'll be able to advance the test fort.
(0017817)
kwieland   
2011-05-21 17:28   
My fort went from 12 FPS to 20 FPS (which is significant) after I removed the windmills. When I disconnected the mist generator, it didn't really change anything. Removing the windmills had a big effect, though.
(0017885)
Hieronymous Alloy   
2011-05-28 14:35   
[quote]

Another bit of profiling results: when you're trying to reproduce a bug using one miner, the other dwarves have nothing to do - and when they have nothing to do they talk and party, and accumulate a history of a few hundred 'talked to whatever' thoughts per dwarf. Since every thought has to be checked every frame in case it is old enough to be deleted, this also causes additional load that reached 8% in the worst case during my experiments

[/quote]


It would seem like a simple fix for this would be to only check re: deleting outmoded thoughts once every game-month or so.
(0017893)
ag   
2011-05-28 23:23   
(edited on: 2011-05-28 23:37)
... or don't accumulate identical "talked" thoughts. There is logic for removing or coalescing duplicates, but it seems it doesn't work for this specific thought type, at least in some circumstances.

The flow engine can probably be improved by mirroring the two most important flags into a dense integer array, ordered in the way the flow engine wants to walk the blocks (i.e. lowest z to highest and so on), and organized so that the index can be easily computed from the block coordinates without fetching the block structure. This would allow the cpu caches and prefetch engine to be utilized to their full capabilities in the idle mode.

> I looked (at the time) in oprofile's state dir, and only saw states for the root and kern users.

Those actually mean the filesystem root, and kernel space code (which can be loaded from who knows where by the bootloader).
(0018154)
Solra Bizna   
2011-07-08 02:15   
(edited on: 2011-07-08 02:37)
I looked at this again just now, and realized that the data was still stored. I'm fairly sure I did nothing differently this time, but I was able to get some apparently valid data out.

This is the aforementioned fort with no vermin and no underground plants.

http://virus.tejat.net/private/public/sample1.txt [^]
http://virus.tejat.net/private/public/sample1.svg [^]

Heartened by this, I'm going to continue with this fort and get another sample if the tickrate goes below 60 again.

Edit: My tickrate went to 100 and is now sticking there comfortably. WTF? To make matters stranger, this is associated with an increase in flagarrayst::has_flag{flag}'s %events from 20% to 35%. Data is in the same place as above, but sample2 instead of sample1.
(0018155)
kwieland   
2011-07-08 08:33   
Interesting. It looks like creature::?updateTemp{temp,flag,fct} still take a lot of processing power. This is with temperature turned off?
(0018165)
Solra Bizna   
2011-07-08 23:49   
I have temperature turned on again.
I've been playing this fort for another several years, and have had occasional temporary dips down to 80, but none nearly as long or as bad as the drop to 60 when I was digging the pit outside. In particular, I've done a huge amount of excavation underground and created a huge number of items with no performance loss. Since there are no underground plants here, the above-ground pit has been the only real digging I've done that increased the plant load. I've even started pumping magma to the surface (the purpose of the pit) and emptied an underground lake without any lag.
I can get another sample if it'll help.
(0018197)
Solra Bizna   
2011-07-11 00:49   
(edited on: 2011-07-11 00:50)
(Thanks, Dwarfu.)

sample3 was taken during the tantrum spiral that may see this fort finally die. (Strong military + tantrum spiral = mass graves, and mine was about 60 legendaries strong.) The tickrate has been between 60 and 70 since the series of ambushes that caused the first death, but had otherwise been holding between 90 and 100. I've dug and done far more than I normally do before the lag hits. I'm going to start a new fort with relatively vanilla raws and a small population limit, run it until it hits 20ish, and then make a sample4.
(0018203)
kwieland   
2011-07-11 10:16   
Sounds promising. So you don't think temperature is playing a role, then? Even on your screw pump stack?
(0018207)
Solra Bizna   
2011-07-12 02:50   
I think temperature (and fluid flow) causes a little lag, but it's mostly constant and, especially when dealing with pump stacks, easily controlled. Even the small amount of extra load from lots of small pockets of magma can be eliminated by purging the stack when it's not in use.
(0018321)
Solra Bizna   
2011-07-27 05:50   
Apparently, temperature has been off for all the samples I've taken. My latest test fort (which I have little time to manage) had temperature off, too. I'd turn it back on, but DF crashes after a second or so if I do...
I've dug more than 10,000 tiles and experienced no tickrate drops beneath 100, but I also haven't breached a cavern layer yet.
(0020308)
Solra Bizna   
2012-02-20 18:39   
Lack of time and motivation has stalled my investigations until now. Heartened by reports of improved performance, I dusted off my DF-related stuff for 0.34.02. After moderate excavation and a huge population explosion, my tickrate is still in the 98-102 range. There are intermittent slowdowns while I'm pumping water out of my aquifer, but otherwise it is stable. Artifacts are off, other game settings are at defaults.
I'm sitting down to do more forting now, with crossed fingers. (Playing the game with crossed fingers is an interesting challenge sometimes.)
(0020315)
Footkerchief   
2012-02-20 19:12   
I'm going to mark this as fixed since it's become too generalized for Toady to act on, although I'll point him toward the interesting stuff people posted in notes here.