| <<<Back 1 day (to 2015/02/05) | 20150206 |
mvrhel_laptop | ok. I think I have a good start on getting this thing fixed. taking a break for a bit. bbbiaw | 00:15.08 |
chrisl | kens: I've just sent a mail to rayjj and cc'ed tech with various font related numbers in it - could you point Ray at it when he comes online? (although he'll probably read this in the logs, so......) | 09:16.24 |
kens | OK no problem | 09:16.32 |
chrisl | Thanks, and that's me done for the week :-) | 09:16.51 |
kens | Bye, have a good weekend | 09:17.01 |
chrisl | Thanks, you too | 09:17.06 |
rayjj | kens: before you mention it, I did see the email from chrisl (and the mention of it here) | 15:47.54 |
kens | OK rayjj | 15:48.06 |
| I'm about to post something on thet ATS files and ram usage | 15:48.18 |
| 1 second# | 15:48.23 |
| OK there. | 15:48.55 |
| It looks like its something to do with GC and the fact that the profile data is not visible to the garbage collector | 15:49.26 |
| We have > 700 ICCBased colour spaces which are all garbage collected at once. The problem is that each of those has a profile and some of those profiles are quite large (> 500Kb). I'm assuming that we don't gc earlier because the garbage collector doesn't think that enough memory is being used, because it can't see the 400Mb or so being used by the profiles..... | 15:50.48 |
rayjj | kens: yeah, that would make sense -- if a GC'ed item has a finalize that takes care of freeing some non-gc memory, then it won't get counted. | 15:55.38 |
kens | I shoudl probably mention that the profiles do all get freed before final exit, it just seems to be a problem in the interim. There doesn't appear to be a memory leak as such | 15:56.23 |
| I'm not sure what (if anything) to do about this, the obvious answer would be to move all the profiles into GC memory, but that looks like it will be hard and have a decent bug tail, so I definitely don't want to do it just now. | 15:57.04 |
henrys | rayjj: I'm going to look at doing type 2 non-otf in pcl today. It looks like a good savings. | 15:57.21 |
rayjj | kens: and I assume that it isn't easy to determine that a color space is no longer used/needed, so free it explicitly (but it may be just that the the designers were lazy about it) | 15:57.31 |
kens | rayjj I don't think we can ever tell that a colour space is no longer used, its a PostScript object, so we'd have to traverse the GC pointers (I htink) | 15:58.01 |
| I did try putting an explicit vmreclaim after every form execution but it made no difference. | 15:58.22 |
rayjj | kens: probably it's at a different save level, so protected from GC | 15:58.54 |
kens | THat is possible, the page content stream starts with a gsave | 15:59.10 |
rayjj | kens: PDF uses (abuses) save/restore to handle the ExtGState | 15:59.42 |
kens | I admit there were a few profile allocations which puzzle me, but overall, the main 'problem' seems to be the fact that we just end up with an awful lot of colour spaces hanging around | 15:59.48 |
| It might be something to do with the unusual number of forms (> 1000) in the job. Especially since they all declare transparency groups (even though many don;t do any transparency) and some of them call other forms.... | 16:00.41 |
| There's a load of ExtGstates too.... | 16:01.25 |
| Anyway, its taken me all day so far to get to this point :-( | 16:02.26 |
| The problem with determining if a colour space is no longer used is gsave/grestore. If I set a complex space (say ICCBased, then do a gsave, then change to a smiple space (eg CMYK) the complex space is still referenced, but the code that sets the colour space cannot tell, so it never tries to free colour spaces, it leaves it up to the garbage collector. The alternative would be to reference count colour spaces, and free them whe | 16:07.49 |
| n the ref count goes to 0, but that would mean couting up the colour space reference on each gsave, and down on each grestore. And I'm not certain how to handle nested gsaves in that case.... | 16:07.50 |
| Oh and then there's save nad restore too, that's a problem.... | 16:10.29 |
henrys | kens: I thought color spaces were reference counted in gsave/grestore. | 16:14.15 |
kens | henrys, no idea | 16:14.25 |
| Lots of things are reference coutned and/or garbage collected. | 16:15.06 |
rayjj | kens: I have to run my son to school, then take my car in. bb in about 30 min | 16:15.25 |
kens | NP | 16:15.30 |
| Also we have the potential problem of storing a colour spce in a dictionary (or other composite object) and pulling it bakc out later. | 16:15.50 |
| If we've freed the ICC profile associated with it, that's going to go badly wrong | 16:16.12 |
henrys | kens: I couldn't find it quickly in the code but I did a simple check in gdb and the reference counts for color spaces increment on gsave and decrement on restore. | 16:24.10 |
kens | henrys, that may well be true, but what happens if I do 'currentcolorspace' and store the result in a PostScript dictioanry ? | 16:24.36 |
| I doubt the reference count will change, but the space will still be referenced even after I change colour space | 16:24.55 |
| I can play with it some more in a second, I'm looking at a pdfwrite font problem at the moment, I suspect I know what's wrong | 16:25.24 |
| Just need to prove it so I can tell the user why. | 16:25.33 |
henrys | kens: you have to increment the rc if the dictionary is going to hold the colorspace, and decrement the rc in the dictionary finalize in case the dictionary is gc'd I guess. | 16:26.41 |
kens | henrys I don't believe there's any way for the code to know that I have taken a colour space and put it in an arbitrary dictioanry, that's my point. | 16:27.16 |
| Unl;ess we track reference counts when we store objects in dictioanries, which we may do, memory in GS isn't my strong point | 16:27.58 |
| I have enough other problems areas to keep me confused..... | 16:28.14 |
Robin_Watts | kens: Surely we must do. | 16:28.15 |
henrys | kens: I would think we'd have to or we'd have very serious leaks. | 16:28.20 |
kens | Robin_Watts : we would not have memory leaks | 16:28.31 |
| The garbage collector traks the dictioanaries, each dict can declare it points to other compound objects, tracking into those also reveals other poitners and so on | 16:29.02 |
| Remember, ech dictioanry we create must be created in userdict or systemdict | 16:29.26 |
Robin_Watts | I understand how a garbage collector works :) | 16:29.36 |
kens | OK. I'm not saying that *is* how it works, I don;t know because I don;t mess about in this area on the whole | 16:30.01 |
| And right now I'm bakc in font land again | 16:30.10 |
Robin_Watts | However, if you layer ref counting on top of a garbage collector, then the point of that is so you can free things when the ref counts go to zero. | 16:30.15 |
| hence you must ref count correctly. | 16:30.22 |
kens | You are assuming we refernce count correclty :-( | 16:30.34 |
| I would not be so bold | 16:30.46 |
henrys | I'm sure we don't reference count properly and that is the source of the problem. | 16:31.14 |
Robin_Watts | The *sole* purpose of ref counting is so that we can free when it goes to zero. | 16:31.18 |
kens | Robin_Watts : yes, but this is Ghostscript...... | 16:31.31 |
Robin_Watts | If we don't free when we go to zero, then there is no point in ref counting. | 16:31.40 |
kens | Yep, and your poitn is ? :-) | 16:31.49 |
| I'd not guarantee anything without chekcing it personally | 16:32.10 |
Robin_Watts | Now, we might cock up the ref counting, and leave it incremented in cases where we shouldn't, in which case we will be saved by the gc. | 16:32.18 |
kens | I'll look at it again, after I get finished with this font | 16:32.23 |
Robin_Watts | But certainly we can never get it wrong the other way around. | 16:32.32 |
kens | : Robin_Watts that's rather the point. We end up with colour spaces which (eventually) get garbage collected, I have no idea what their ref counts are, quite possibly they are incorrect, I have no idea | 16:33.24 |
| THe ref counts on the profiles are correct (they aren't garbage collected) | 16:33.46 |
Robin_Watts | kens: Right. | 16:33.57 |
kens | Damn, went atraight past my breakpoint :-( | 16:34.06 |
| Excuse me a minute, I do need to concentrate here | 16:34.16 |
Robin_Watts | sure. | 16:34.24 |
henrys | I'm wondering if Robin_Watts color space swapping code got this messed up it looks like when you do the swap you are just plowing over the rc's. I must be missing something. | 16:35.18 |
Robin_Watts | henrys: Surely the RCs are in the color spaces? | 16:38.19 |
Robin_Watts | will have a look. where are you looking? | 16:38.37 |
henrys | this assinment doesn't make sense to me: pgs->color[0].color_space = pgs->color[1].color_space gstate.c:1200 | 16:39.01 |
| Robin_Watts: what is the rc's are different? | 16:39.20 |
| s/is/if | 16:39.36 |
Robin_Watts | The rc's will be pgs->color[0].colorspace->ref_count or something, right? | 16:39.43 |
henrys | p pgs->color[0].color_space.rc | 16:40.24 |
Robin_Watts | Right. | 16:40.30 |
| So I'm swapping pgs->color[0].color_space with pgs->color[1].colors_space | 16:40.55 |
| There is no change in the ref counts at all. | 16:41.04 |
| both color_spaces have the same number of references to them afterwards as they did beforehand. | 16:41.20 |
henrys | Robin_Watts: okay right | 16:41.37 |
Robin_Watts | phew :) | 16:41.44 |
henrys | but I do know there are color space referenct count problems in the code and I'm sure that's what kens is up agains. | 16:42.26 |
Robin_Watts | henrys: right. | 16:42.37 |
| So... run a memento build and disable garbage collection. look for leaks ? | 16:42.58 |
kens | It doesn't leak | 16:43.05 |
| Well, not if you have GC | 16:43.12 |
Robin_Watts | hence why I said disable garbage collection. | 16:43.23 |
kens | Hmm,this font problem is not the provblem I thought it was | 16:43.27 |
Robin_Watts | and disable the chunk freeing. | 16:43.41 |
kens | You can't totally dissable GC | 16:43.44 |
Robin_Watts | You can :) | 16:43.50 |
kens | Oh chunk freeing | 16:43.51 |
| I'm guessing that will end upo with a monstrous amount of leaks | 16:44.06 |
| This is a pretty big PDF file | 16:44.19 |
Robin_Watts | Right, you'll end up with lots of memory that gc should have thrown away not being thrown away. | 16:44.29 |
kens | Yes, but I think most of tehm won't be colour spaces | 16:44.45 |
Robin_Watts | but assuming we have an appropriate Memento_label in the code, you'll be able to see which ones are colorspaces | 16:44.56 |
henrys | it's painful but -Z^ is useful for tracking down the rc stuff. | 16:44.57 |
| kens: but that may be more for rayjj or chrisl, why did you get stuck with it? | 16:45.21 |
Robin_Watts | (Memento is not the only way of doing this, it's just a way) | 16:45.29 |
kens | henrys it got assigned as 'PDF interpreter', I did query it, but.... | 16:45.46 |
| I don't believe that 2 of the 'propblems' are PDF itnerpreter at all, the middle one might be, I haven't had time to look at it yet | 16:46.15 |
| Ray did start in on it last night, which is why I knew to look at profiles | 16:46.39 |
henrys | bbiab | 16:48.30 |
rayjj | sorry -- I looked over the logs. kens -- if you want to punt it back, please feel free, and if the other problem is different to the two that are colorspace related, please open a separate issue | 16:56.04 |
| kens: when I opened the bug, I (like many users that opened the bug) didn't know if it was the PDF interp or what without investigating it. I mainly opened it to track the issue | 16:57.12 |
| kens: and I purposely left it at P4 since I am not sure that it is urgent (even if it seems like bad behavior) | 16:57.53 |
| going to take the car in now. bbiaw | 16:58.18 |
kens | rayjj (for the logs) I'm 'reasonably' confident the middle file is not related to ICC profiles, because the memory usage is the same wqith 8.71 ;-) | 17:02.23 |
| I've not had a chance to look at it yet | 17:02.31 |
| FWIW hte 4 profiles allocated in the first form are from zbegintransparencymask. It seems that the first time we do a mask we create gray, rgb and cmyk profiles for masks, and attach them to the icc_manager. It looks like htose persist until the device is terminated and the icc_manager cleaned up. So those make sense. | 17:31.00 |
| OK I'm off, night all | 17:35.57 |
mvrhel_laptop | ok. looks like I may have stefan's problem figured out and a rough fix in place. Need to clean a few things up | 19:49.41 |
| works quite nicely | 19:49.52 |
| ok. clean up done. need to do a bit of testing with a few more color spaces and the cluster push | 22:04.11 |
| Forward 1 day (to 2015/02/07)>>> | |