IRC log of #zope for Friday, 2015-01-09

*** Jan_Garaj3_ has joined #zope00:16
*** J1m_ has quit IRC00:17
*** Jan_Garaj3 has quit IRC00:17
*** Jan_Garaj3_ is now known as Jan_Garaj300:17
*** J1m_ has joined #zope00:18
*** TresEquis has joined #zope00:31
*** TresEquis has quit IRC00:51
*** menesis has quit IRC01:05
*** J1m_ has quit IRC01:08
*** Jan_Garaj3 has quit IRC01:52
*** nueces has quit IRC02:12
*** menesis has joined #zope06:12
*** menesis has quit IRC06:34
*** bosim has joined #zope08:01
*** bosim has quit IRC08:02
*** bosim has joined #zope08:03
*** __mac__ has joined #zope08:17
*** __mac__ has quit IRC08:26
*** __mac__ has joined #zope08:33
*** yvl has joined #zope09:00
*** agroszer has joined #zope09:23
*** alecm has quit IRC09:46
*** Jan_Garaj3 has joined #zope09:48
*** tisto has joined #zope09:58
*** River_Rat is now known as RiverRat10:09
*** MrTango has joined #zope10:58
*** maurits has joined #zope12:02
*** Jan_Garaj3 has quit IRC12:05
*** jakke has joined #zope12:28
jakkeHi Guys, anyone has input on this question: ?12:29
jakkeabout 2 different versions of _zope_proxy_proxy.c files being used in zope?12:29
mgedminit's probably an oversight12:39
mgedminI'd be tempted to look at the histories of the files and contact the contributors with this questionh12:40
mgedminha ha
mgedminyes they're supposed to be synchronized12:41
mgedmindo you want to file a bug?12:43
mgedminjakke: ^12:43
mgedminincidentally, zope.container has one fix (pypy support) that didn't make it to zope.proxy, not the other way around, AFAICS12:44
jakkemgedmin, don't know, still digging into a very strange error12:49
jakkeloading an object returns an empty object instead of object with data12:49
mgedminare you accessing __dict__ directly?12:50
jakkeand during the diving into that issue, we found this mismatch12:50
jakkeno, it's all standard zope code12:50
jakkeobjects stored in __annotations__, which is a BTree12:50
mgedminhmm... are you storing LocationProxy/ContainedProxy wrappers in the ZODB?12:51
jakkeapparently that's what happening with plone portlets yes12:52
jakkethey inherit in their chain from zope.contained12:53
mgedminI remember having some trouble when we tried to store unicode strings in a container12:54
mgedminthey got wrapped in a ContainedProxy, which then got wrapped in a SecurityProxy12:54
mgedminand in a new transaction when we loaded those and tried to construct form fields dynamically we ended up having to removeSecurityProxy() from the string before we could actually use it as a field title12:55
do3ccthe zope-cmf mailing list just exploded in activity ;-)12:55
mgedminwhich was a bit of a wtf until we figured out where those security-proxied strings came from12:55
jakkethat's an interesting track, check wether the previous version contained unicode :)12:57
mgedminthe wtf was because normally strings are rocks and have no proxies, and therefore they have no security declarations and therefore if you get a security-proxied string somehow you can't do anything with it12:58
mgedminwhich is probably different from your problem12:58
mgedminwhen you say "an empty object", what do you mean, exactly?12:59
mgedminwhat's the class/type of the object?12:59
mgedminis it wrapped in any proxies?12:59
mgedminwhat does the pickle data look like?12:59
jakkewell, it's plone code, we've seen in now in portlets and collections13:00
mgedminzodbbrowser might or might not be helpful here -- I'd use it13:00
mgedmin(assuming it works with plone)13:00
jakkeso we get __annotations__, wich are a BTrees.OOBTree.OOBTree13:01
jakkeand one of the objects stored in that BTree, is a valid object, but it contains no attributes13:02
jakkepickle looks healthy, bin/instance debug I can access the objects as well13:02
jakkecompared the pickle of a "broken" portlet of that with a 'functional portlet', and they look the same, except for the attributes in one object13:03
mgedminwhat's the class of the object?   does it differ from type(obj)?  what does it inherit?13:03
mgedminare all attributes missing?  some of them?  what are their names?13:04
jakkeall are missing13:04
jakkechecking for class and type now13:04
mgedminwhen you say "missing", do you mean you get AttributeError?13:05
mgedmindefault values from class-level attributes?13:05
mgedminempty-looking __dict__ in a REPL prompt?13:05
jakkelast thing: empty looking __dict__13:05
jakkeand you get the default class attribute values if you try to acces these13:06
mgedminhave you called obj._p_activate() before looking at obj.__dict__?13:06
mgedminah, ok, you have13:06
jakkenot explicitly13:06
mgedminso the state pickle is missing attributes?  interesting13:06
mgedminI'd definitely want to see the history of that particular object with zodbbrowser13:07
jakkeyups, and only for 1 object as far as we've seen13:07
jakkenot that much of a history, depends on when the packing has been done13:07
jakkesome only have 1 history object, being the "new state" itself, which is weird in itself13:07
mgedminwell, if they've been packed, that's what you'd see13:08
jakkecause if it's a new state, I'd expect the previous state to be there as well13:08
mgedminis there DC metadata?13:08
jakkeDC as in Dublin Core?13:08
mgedminI'm just wondering if the timestamp of the oldest (the only) transaction touching this object matches its creation time in DC metadata13:09
mgedminif yes, we know something13:09
mgedminif no, older states got lost during packing13:09
jakkeapparently there is13:09
mgedmin"new state" in zodbbrowser's history doesn't mean much; iirc I'm diffing the unpickled state against an empty dict to show the very first revision13:10
mgedmindon't read too much into the wording (or, alternatively, send me patches to improve it ;)13:10
jakkenot using zodbbrowser, I load it from instance/debug and db.history calls :)13:11
mgedminah, cool13:11
mgedminI used to know how to do that13:11
mgedmin(and then got tired of the manularity and convinced a junior programmer to write zodbbrowser for me)13:11
jakke:D, I know it now, because I'm diving way deeper than I wanted too, probably forget about it when this task is finished ;-)13:12
jakkewe compared a "new empty state" with an brand new object of the same type, empty, and it's the same13:13
mgedminis this related to the _zope_proxy_proxy.c thing or something unrelated?13:14
jakkethe object that gets "initialized empty" is a zope.contained object, that's how we boiled it down to the _zope_proxy_proxy.c13:15
jakkedon't know if the cause is there, we've just noticed the mismatch13:15
mgedminare you running on pypy?13:16
jakkeno, standard python2.713:17
mgedminthen there are no meaningful differences between the two .c files13:17
jakkegood to know, thanks :)13:17
mgedminis the state dict complex?  does it have mutable non-persistent subobjects?13:18
jakkeno, everything should be persisted13:19
jakkeok mgedmin, I gatherd some context for you13:37
jakkethe blc is the broken one, the wlc is the working one13:37
jakkeas you can see is type() and __class__ the same, but one has an address, the odther doesn't13:37
mgedminand type(blc_data['navigation'].__annotations__['plone.portlets.assignmentsettings'].data) is ...?13:38
jakkeand the broken one has an empty dict, compared to a "working one"13:38
jakke>>> type(blc_data['navigation'].__annotations__)13:38
jakke<type 'BTrees.OOBTree.OOBTree'>13:38
mgedminthat's not what I asked about13:39
jakkeright, sec13:39
jakke<class 'persistent.mapping.PersistentMapping'>13:40
jakkesame goes for the working13:40
mgedmintype(blc_data['navigation']) versus type(wlcdata['navigation']) ?13:41
*** J1m has joined #zope13:41
jakkeboth the same: <class ''>13:42
mgedminhow can they have different repr()s?13:42
jakkebeacuse the wlcdata['navigation'].id has a value: u'navigation'13:43
jakkeand the blc_data['navigation'].id is ''13:44
mgedminoh, there's an if in the __repr__?13:44
jakkeit's been some time since I've checked there13:44
*** LeoRochael has joined #zope13:45
jakkebut id is a wrapper for __name__, and repr uses __name__13:45
jakkeI suppose there is kind of a lookup based upon the __name__ or its presence, but I don't remember exactly anymore13:45
mgedminI see:
jakkebut that's quite normal behavior for objects that lost their __name__ or id, I've seen that with other objects too13:46
mgedminI'm not used to debugging Zope 2 :)13:46
jakkewe're kind of stuck to it with plone ;-)13:47
mgedminso you've narrowed it down to broken data in the zodb13:47
jakkewell, yes and no13:48
jakkeit's stored broken in zodb, that much is for sure13:48
jakkewe still don't know yet why it gets broken13:48
mgedminright, the question is: what code breaks it13:48
mgedminis it the initial transaction that adds it?  a subsequent packing?13:48
mgedminis this filestorage?  relstorage?13:48
mgedmindo you have a way to reproduce the issue (i.e. add a new working portlet and make it break)?13:49
jakkewhat we're thinking of now, is that the loading of the object goes bad, and a "backup path" loads an empty object, instead of a data packed object, and that the transaction machinery detects a "change in object" and stores the new one13:49
jakkeno, we cannot reproduce it, that's a major issue, we just "wait and see" and do post mortem analysis13:49
jakkeand it goes together with a "document_view by None" in the undo log, but that doesn't add much info either13:50
jakkepacking is not related13:50
mgedmindocument_view, interesting13:50
jakkeit's relstorage13:50
mgedminI'd really like to see this with zodbbrowser13:50
mgedminlike look at the oid of blc_data['navigation'].__annotations__['plone.portlets.assignmentsettings']13:51
mgedmindoes it change?13:51
mgedminbetween the working version and the broken version, I mean13:51
mgedmin(first you'd have to find an object that used to work and then broke, but has all the history)13:51
jakkeoften I only have 1 version in the history, which I think is fairly change13:51
jakkebut I'll doublecheck13:52
jakkeso it could be a new object as well, point is that portlets aren't changed that often13:52
mgedminwell, actually, track the entire chain from the topmost thing13:52
jakkeso it could be packed as well, but if it's an update, at least 2 versions should be visible in the history13:52
mgedminalso, the empty __name__, is that a bug?13:52
jakkeit's a symptom, don't know what causes it13:53
jakkea colleague assumed it's because loading objects from zodb is not done via the constructor but via new() and then add the data to the object13:54
jakkehaven't touched that bit of code yet though13:55
mgedminthat's how most pickles work anyway13:55
jakkebut if you do a new() and fail to add data to it, it could explain the loss of __name__ too13:55
mgedmina failure in __setstate__ would show up in the logs, though13:55
jakkegrepping the logs, but I don't think we've seen an error there13:58
mgedmindoes zodbbrowser even work with relstorage?13:58
jakkeI have an export on filestorage, so no problem :)13:59
mgedmindoes it include history? :)13:59
jakkeshould yes, it's supposed to be a full export13:59
mgedmin"full" is nicely non-specific14:00
jakkeI'll have  a look, adding it to buildout now14:00
*** LeoRochael has quit IRC14:04
jakkeaccording to my logs about the issue, the export seems to contain history, since I've been querying it14:06
jakkebut still I haven't check if it's a new object or not, have to have a look14:08
jakkesee if there is a previous version of the containing object available14:08
jakkeand then check the _p_oid for both "broken objects"14:08
jakkeboth versions of the broken in the end object I mean14:09
jakkepacked, darn14:10
mgedminmaybe it was broken from the beginning?14:13
jakkeno, for sure not14:17
jakkeusers complained when their navigation "all of a sudden" was broken14:17
mgedminany correlation with server restarts?14:18
jakkemaybe, if I'm lucky, I can find it back in an old old old backup, but I doubt that14:19
jakkeno, seems to be a correlation with number of visits though14:19
jakkethe start of the academic year always causes more visits, and this year also more broken portlets,14:19
jakkenow everything is back to normal, and the frequency is down14:19
mgedminbroken conflict resolution code?14:20
jakkeservers have a standard restart cycle every month or so14:20
jakkemgedmin, I like your thinking!14:21
mgedminstill, that means portlets get modified during a view operation14:22
mgedminwhich would be inefficient, if not outright wrong14:22
jakkeI'll get you a log pastebin14:22
jakkeit's not a realated log, but it seems a good point to look into14:24
mgedminiirc oobtrees have some interesting conflict resolution code14:24
mgedminthat might be wrong for some application semantics14:24
jakkeit goes fine in 90+ % of the cases14:25
mgedmin mentions some dangers with situations where you have multiple persistent objects that have to be kept in sync14:26
jakkebtrees in zodb is, according to some document I read some time ago, also not always the better choice14:29
jakkezodbbrowser does not want to cooperate14:31
jakkettributeError: class MultiHook has no attribute '__repr__'14:31
mgedminmind pasting the traceback to
mgedminI thought I wrapped all repr() calls with try/except, but apparently missed some :/14:32
jakkewhat name do you want me to give it?14:33
mgedmin"AttributeError: class MultiHook has no attribute '__repr__'" is a fine issue title14:33
*** menesis has joined #zope14:35
jakkethere you are :)14:36
jakkeit used to work though, I've used zodbbrowser before14:36
jakkeok, I'll look into those conflict errors at the time of the messy transaction, could give us some more clues14:39
jakkewould be awesome14:39
jakkeno luck, no conflict resolution logs for that timeframe :(14:55
*** giacomos has joined #zope15:06
*** J1m has quit IRC15:24
*** J1m has joined #zope15:47
*** J1m has quit IRC15:51
*** J1m_ has joined #zope15:57
*** J1m has joined #zope16:07
*** J1m_ has quit IRC16:10
*** agroszer has quit IRC16:29
mgedminjakke, zodbbrowser 0.11.2 fixes that AttributeError16:35
*** bosim has quit IRC17:15
*** alecm has joined #zope17:17
*** __mac__ has quit IRC17:38
*** __mac__ has joined #zope17:51
jakkeawesome mgedmin!, I'll try after the weekend, now is time to go home :)18:18
jakkestarted buildout already, so it's waiting for me on monday morning18:19
*** yvl has quit IRC18:51
*** giacomos has quit IRC19:15
*** __mac__ has quit IRC19:49
*** Jan_Garaj3 has joined #zope20:01
*** nueces has joined #zope20:10
*** Jan_Garaj3 has quit IRC20:20
*** tisto has quit IRC20:22
*** __mac__ has joined #zope20:23
*** __mac__ has quit IRC20:47
*** __mac__ has joined #zope21:15
*** __mac__ has quit IRC21:26
*** maurits has quit IRC21:30
*** __mac__ has joined #zope21:34
*** __mac__ has quit IRC21:41
*** __mac__ has joined #zope21:52
*** __mac__ has quit IRC21:53
*** J1m has quit IRC21:54
*** J1m has joined #zope22:44
*** Jan_Garaj3 has joined #zope22:48
*** MrTango has quit IRC22:59
*** kiorky has quit IRC23:32
*** kiorky has joined #zope23:33
*** kiorky has quit IRC23:44
*** kiorky has joined #zope23:44

Generated by 2.15.1 by Marius Gedminas - find it at!