Using 2.0.50_pre16, here is what I did: - first I've masked tpb-0.6.0 and downgraded to 0.5.1. The 0.6 was not cleaned. - then I've updated my world (was already partially done, so tere were 3 pkg only): --------------------------------------------------- % emerge -uD world Calculating world dependencies ...done! >>> emerge (1 of 3) net-www/apache-2.0.48-r2 to / ... >>> net-www/apache-2.0.48-r2 merged. >>> clean: No packages selected for removal. >>> emerge (2 of 3) media-libs/pdflib-5.0.2 to / ... >>> media-libs/pdflib-5.0.2 merged. >>> clean: No packages selected for removal. >>> emerge (3 of 3) app-misc/screen-4.0.1-r2 to / ... >>> app-misc/screen-4.0.1-r2 merged. app-misc/screen selected: 4.0.1-r1 protected: 4.0.1-r2 omitted: none ... >>> Unmerging app-misc/screen-4.0.1-r1... >>> Auto-cleaning packages ... sys-apps/tpb selected: 0.6.0 protected: 0.5.1 omitted: none ... >>> Unmerging sys-apps/tpb-0.6.0... ... --------------------------------------------------- - then I 'emerge clean' manually: --------------------------------------------------- % emerge clean net-www/apache selected: 2.0.48-r1 protected: 2.0.48-r2 omitted: none ... >>> Unmerging net-www/apache-2.0.48-r1... ... --------------------------------------------------- (Note that the media-libs not being cleaned is a normal behavior: it was new in this slot.) So it seems that some cleanups are delayed. 'Tpb' was not cleaned when I've updated it, and then 'apache' neither. I've not tried to find the "why" yet, but I guess it can comes from the counter and treewalk changes of _pre15, no? Reproducible: Always Steps to Reproduce:
Ditto here. I usually manually emerge world packages one ebuild at a time (out of habit). I see the same thing with AUTOCLEAN. For example, I updated netpbm tonight and the emerge did not clean the old version. I then updated wxglade and portage finished the wxglade emerge THEN cleaned netpbm. The old version of wxglade did not get cleaned. 1074138757: Started emerge on: Jan 14, 2004 21:52:37 1074138757: *** emerge --verbose --update netpbm 1074138757: >>> emerge (1 of 1) media-libs/netpbm-10.11.15 to / 1074138757: === (1 of 1) Cleaning (media-libs/netpbm-10.11.15::/usr/portage/media-libs/netpbm/netpbm-10.11.15.ebuild) 1074138760: === (1 of 1) Compiling/Merging (media-libs/netpbm-10.11.15::/usr/portage/media-libs/netpbm/netpbm-10.11.15.ebuild) 1074139469: === (1 of 1) Post-Build Cleaning (media-libs/netpbm-10.11.15::/usr/portage/media-libs/netpbm/netpbm-10.11.15.ebuild) 1074139472: >>> AUTOCLEAN: media-libs/netpbm 1074139472: --- AUTOCLEAN: Nothing unmerged. 1074139472: ::: completed emerge (1 of 1) media-libs/netpbm-10.11.15 to / 1074139472: *** Finished. Cleaning up... 1074139478: *** exiting successfully. 1074139480: *** terminating. 1074139662: *** terminating. 1074139679: *** terminating. 1074139687: Started emerge on: Jan 14, 2004 22:08:07 1074139687: *** emerge --verbose --update wxglade 1074139687: >>> emerge (1 of 1) dev-util/wxglade-0.3.1-r1 to / 1074139687: === (1 of 1) Cleaning (dev-util/wxglade-0.3.1-r1::/usr/portage/dev-util/wxglade/wxglade-0.3.1-r1.ebuild) 1074139690: === (1 of 1) Compiling/Merging (dev-util/wxglade-0.3.1-r1::/usr/portage/dev-util/wxglade/wxglade-0.3.1-r1.ebuild) 1074139725: === (1 of 1) Post-Build Cleaning (dev-util/wxglade-0.3.1-r1::/usr/portage/dev-util/wxglade/wxglade-0.3.1-r1.ebuild) 1074139728: >>> AUTOCLEAN: dev-util/wxglade 1074139728: --- AUTOCLEAN: Nothing unmerged. 1074139728: ::: completed emerge (1 of 1) dev-util/wxglade-0.3.1-r1 to / 1074139728: *** Finished. Cleaning up... 1074139734: === Unmerging... (media-libs/netpbm-10.11.14) 1074139747: >>> unmerge success: media-libs/netpbm-10.11.14 1074139749: *** exiting successfully. 1074139750: *** terminating.
Sorry, forgot to mention I'm running portage-2.0.50_pre16 but looking back at my emerge log it DOES look like the problem began under pre15 (or, at least after the first few emerges). 1073965403: Started emerge on: Jan 12, 2004 21:43:23 1073965403: *** emerge --verbose --update portage 1073965403: >>> emerge (1 of 1) sys-apps/portage-2.0.50_pre15 to / 1073965403: === (1 of 1) Cleaning (sys-apps/portage-2.0.50_pre15::/usr/portage/sys-apps/portage/portage-2.0.50_pre15.ebuild) 1073965406: === (1 of 1) Compiling/Merging (sys-apps/portage-2.0.50_pre15::/usr/portage/sys-apps/portage/portage-2.0.50_pre15.ebuild) 1073965537: === (1 of 1) Post-Build Cleaning (sys-apps/portage-2.0.50_pre15::/usr/portage/sys-apps/portage/portage-2.0.50_pre15.ebuild) 1073965538: >>> AUTOCLEAN: sys-apps/portage 1073965543: === Unmerging... (sys-apps/portage-2.0.49-r21) 1073965553: >>> unmerge success: sys-apps/portage-2.0.49-r21 1073965557: ::: completed emerge (1 of 1) sys-apps/portage-2.0.50_pre15 to / 1073965557: *** Finished. Cleaning up... 1073965566: *** exiting successfully. 1073965568: *** terminating. 1073965690: Started emerge on: Jan 12, 2004 21:48:10 1073965690: *** emerge --verbose --update gentoolkit 1073965690: >>> emerge (1 of 1) app-portage/gentoolkit-0.2.0_pre4 to / 1073965690: === (1 of 1) Cleaning (app-portage/gentoolkit-0.2.0_pre4::/usr/portage/app-portage/gentoolkit/gentoolkit-0.2.0_pre4.ebuild) 1073965691: === (1 of 1) Compiling/Merging (app-portage/gentoolkit-0.2.0_pre4::/usr/portage/app-portage/gentoolkit/gentoolkit-0.2.0_pre4.ebuild) 1073965712: === (1 of 1) Post-Build Cleaning (app-portage/gentoolkit-0.2.0_pre4::/usr/portage/app-portage/gentoolkit/gentoolkit-0.2.0_pre4.ebuild) 1073965713: >>> AUTOCLEAN: app-portage/gentoolkit 1073965718: === Unmerging... (app-portage/gentoolkit-0.1.38) 1073965723: >>> unmerge success: app-portage/gentoolkit-0.1.38 1073965725: ::: completed emerge (1 of 1) app-portage/gentoolkit-0.2.0_pre4 to / 1073965725: *** Finished. Cleaning up... 1073965727: *** exiting successfully. 1073965891: *** terminating. 1073966657: Started emerge on: Jan 12, 2004 22:04:17 1073966657: *** emerge --verbose --update tar 1073966657: >>> emerge (1 of 1) app-arch/tar-1.13.92-r3 to / 1073966657: === (1 of 1) Cleaning (app-arch/tar-1.13.92-r3::/usr/portage/app-arch/tar/tar-1.13.92-r3.ebuild) 1073966657: === (1 of 1) Compiling/Merging (app-arch/tar-1.13.92-r3::/usr/portage/app-arch/tar/tar-1.13.92-r3.ebuild) 1073966730: === (1 of 1) Post-Build Cleaning (app-arch/tar-1.13.92-r3::/usr/portage/app-arch/tar/tar-1.13.92-r3.ebuild) 1073966731: >>> AUTOCLEAN: app-arch/tar 1073966736: === Unmerging... (app-arch/tar-1.13.92-r2) 1073966742: >>> unmerge success: app-arch/tar-1.13.92-r2 1073966742: ::: completed emerge (1 of 1) app-arch/tar-1.13.92-r3 to / 1073966742: *** Finished. Cleaning up... 1073966751: *** exiting successfully. 1073966758: *** terminating. 1073967058: *** terminating. 1073967112: *** terminating. 1073967128: Started emerge on: Jan 12, 2004 22:12:08 1073967128: *** emerge --verbose --update gl117 1073967128: >>> emerge (1 of 1) games-simulation/gl117-1.1 to / 1073967128: === (1 of 1) Cleaning (games-simulation/gl117-1.1::/usr/portage/games-simulation/gl117/gl117-1.1.ebuild) 1073967129: === (1 of 1) Compiling/Merging (games-simulation/gl117-1.1::/usr/portage/games-simulation/gl117/gl117-1.1.ebuild) 1073967279: === (1 of 1) Post-Build Cleaning (games-simulation/gl117-1.1::/usr/portage/games-simulation/gl117/gl117-1.1.ebuild) 1073967280: >>> AUTOCLEAN: games-simulation/gl117 1073967285: === Unmerging... (games-simulation/gl117-1.0) 1073967289: >>> unmerge success: games-simulation/gl117-1.0 1073967290: ::: completed emerge (1 of 1) games-simulation/gl117-1.1 to / 1073967290: *** Finished. Cleaning up... 1073967298: *** exiting successfully. 1073967298: *** terminating. 1073968223: *** terminating. 1073968231: *** terminating. 1073968236: Started emerge on: Jan 12, 2004 22:30:36 1073968236: *** emerge --verbose --update ncurses 1073968236: >>> emerge (1 of 1) sys-libs/ncurses-5.3-r5 to / 1073968236: === (1 of 1) Cleaning (sys-libs/ncurses-5.3-r5::/usr/portage/sys-libs/ncurses/ncurses-5.3-r5.ebuild) 1073968237: === (1 of 1) Compiling/Merging (sys-libs/ncurses-5.3-r5::/usr/portage/sys-libs/ncurses/ncurses-5.3-r5.ebuild) 1073968662: === (1 of 1) Post-Build Cleaning (sys-libs/ncurses-5.3-r5::/usr/portage/sys-libs/ncurses/ncurses-5.3-r5.ebuild) 1073968662: >>> AUTOCLEAN: sys-libs/ncurses 1073968662: --- AUTOCLEAN: Nothing unmerged. 1073968662: ::: completed emerge (1 of 1) sys-libs/ncurses-5.3-r5 to / 1073968662: *** Finished. Cleaning up... 1073968670: *** exiting successfully. 1073968670: *** terminating. 1073968709: *** terminating. 1073968719: *** terminating. 1073968723: Started emerge on: Jan 12, 2004 22:38:43 1073968723: *** emerge --verbose --update rhythmbox 1073968723: >>> emerge (1 of 1) media-sound/rhythmbox-0.6.4 to / 1073968723: === (1 of 1) Cleaning (media-sound/rhythmbox-0.6.4::/usr/portage/media-sound/rhythmbox/rhythmbox-0.6.4.ebuild) 1073968724: === (1 of 1) Compiling/Merging (media-sound/rhythmbox-0.6.4::/usr/portage/media-sound/rhythmbox/rhythmbox-0.6.4.ebuild) 1073969835: === (1 of 1) Post-Build Cleaning (media-sound/rhythmbox-0.6.4::/usr/portage/media-sound/rhythmbox/rhythmbox-0.6.4.ebuild) 1073969838: >>> AUTOCLEAN: media-sound/rhythmbox 1073969838: --- AUTOCLEAN: Nothing unmerged. 1073969838: ::: completed emerge (1 of 1) media-sound/rhythmbox-0.6.4 to / 1073969838: *** Finished. Cleaning up... 1073969852: === Unmerging... (sys-libs/ncurses-5.3-r4) 1073969873: >>> unmerge success: sys-libs/ncurses-5.3-r4 1073969875: *** exiting successfully. 1073969875: *** terminating.
In Comment #0, I wrote: > the counter and treewalk changes of _pre15 I meant _pre13, sure. Anyway, I've found the bug. It's not really that it has been introduced by the treewalk changes, but more that it now shows up as a side effect. In fact, it is the vardbapi.match() function which has a wrong cache validation logic: when you update one entry in matchcache, you also update the mtdircache for the category, ie. you say "all cache entries of this category are up to date". Which is wrong, since only one has been updated. What seems to happen when you update foo/bar-1.0 to foo/bar-1.1 is, more or less: - match("foo/bar") is called at some point, cache is feed with ['foo/bar-1.0'] - then, in treewalk(), 'bar-1.1' is added to the /var/db/pkg/foo - there are some other calls to match(), for deps different than "foo/bar", but in the "foo" category => they update the category cache timestamp (I don't know exactly where this ones come from, but it's not really important). - then during the pkg clean that should have removed foo/bar-1.0, match("foo/bar") is called again. The /var/db/pkg/foo mtmime has not changed since last match("foo/something") call, and match() returns ['foo/bar-1.0'], and there is nothing to clean. I guess that with the previous treewalk version, there was at some point a call to match(foo/bar) done whereas the /var/db/pkg/foo had just changed, hence the cache entry was correctly updated. I will attach a very quick fix for match() that makes it use a different cache timestamp for each dep query. It fixes the bug, but there is probably something better to do. For instance, one can imagine that when an element is added or removed to var/db/pkg, the matchcache entries matching this element are explicitly removed. There would be no more need for a timestamp validation this way. Well, that just a thought.
Created attachment 23848 [details, diff] matchcache-quickfix.patch
Created attachment 23859 [details, diff] matchcache-fix.patch Here is another version of the fix that is a bit better.
*** Bug 38384 has been marked as a duplicate of this bug. ***
great! I just applyed the second patch in cvs.
Oops, I've returned the result without copying it. I don't remember how it is used after, but it would probably be safer to return a copy in case there is some code which loops with some pop(), or things like this, which would corrupt the cache. Can you manually apply this please?: - return self.matchcache[mycat][mydep] + return self.matchcache[mycat][mydep][:]
What is the different?
Without the [:] copy, if you do this: mymatchlist=blablabla.match("your-dep") ...then mymatchlist references the same list than matchcache["your-cat"]["your-dep"]. Hence, if you then for instance you use your result this way: while len(mymatchlist): x=mymatchlist.pop() ... ...then you will empty your cache entry. With the copy, you get a fresh list that you can destroy without affecting the cache. There were such bugs fixed already in the past: 21 Oct 2003; Nicholas Jones <carpaski@gentoo.org> portage.py: <snip> Fixed caching bug where cache objects were passed back as pointers instead of copies. <snip> I don't want to reintroduce some :)
hmm, I think python returns instance value in 'return value'. I just tested it in my environment. Can you show me example code of it?
P.S. I'm not guru with python, so I'd like to just know that I don't know :)
> Can you show me example code of it? Sure. For instance, in the interpreter: Python 2.3.3 (#1, Jan 8 2004, 00:10:00) [GCC 3.3.2 20031201 (Gentoo Linux 3.3.2-r4, propolice)] on linux2 Type "help", "copyright", "credits" or "license" for more information. >>> mydict={} >>> mydict["a"]=[1,2,3] >>> def get(key): ... return mydict[key] ... >>> l=get("a") >>> l.pop() 3 >>> mydict["a"] [1, 2] <===== here, we have corrupted our dictionnary >>> def getwithcopy(key): ... return mydict[key][:] ... >>> l=getwithcopy("a") >>> l.pop() 2 >>> mydict["a"] [1, 2] <===== here, the dictionnary is still okay >>> In fact, from what I've understood (but I'm also far from being a guru, I've only learned some rudiments of python by playing with the portage code), everything is returned by reference (or pointer, I don't know how they call it) as soon as it is not an atomic type object (like integers).
I didn't know that. Thank you for the explanation. I fixed it in cvs.
*** Bug 38731 has been marked as a duplicate of this bug. ***
*** Bug 38856 has been marked as a duplicate of this bug. ***
*** Bug 37077 has been marked as a duplicate of this bug. ***
supposed to be fixed in 2.0.50 which is stable now. If this bug is not fixed please reopen.
