Issues with Expiration in Couchbase

Filipe Manana added a comment - 28/Aug/12 6:55 AM Chiyoing, while I don't see 0 values in the couchstore and view engine layers for expiration or flags, I noticed there seems to be an extra endianess conversion of fields within the revision: Example, I do this via python: $ ~/couchbase2-4/ep-engine/management ((8440fae...))> python Python 2.7.1 (r271:86832, Jun 16 2011, 16:59:05) [GCC 4.2.1 (Based on Apple Inc. build 5658) (LLVM build 2335.15.00)] on darwin Type "help", "copyright", "credits" or "license" for more information. >>> import mc_bin_client >>> c = mc_bin_client.MemcachedClient(port = 12000) >>> c.vbucketId = 0 >>> c.set("doc4", 111112, 8, "{\"value\": 4}") (1826197228, 48227429387, '') >>> Than at couchstore: $ ../install/bin/couch_dbdump couch/0/default/0.couch.1 Doc seq: 6      id: doc4      rev: 2      content_meta: 0      cas: 48227429387, expiry: 1346265135, flags: 134217728      data: {"value": 4} Total docs: 1 For flags, 134217728 is 8 with wrong endianness. I added the following patch to couch-kvstore.cc: diff --git a/src/couch-kvstore/couch-kvstore.cc b/src/couch-kvstore/couch-kvstore.cc index 4d316c2..978f236 100644 --- a/src/couch-kvstore/couch-kvstore.cc +++ b/src/couch-kvstore/couch-kvstore.cc @@ -246,6 +246,7 @@ CouchRequest::CouchRequest(const Item &it, uint64_t rev, CouchRequestCallback &c      bool isjson = false;      uint64_t cas = htonll(it.getCas());      uint32_t flags = htonl(it.getFlags()); + getLogger()->log(EXTENSION_LOG_WARNING, NULL, "FLAGS: %d\n", it.getFlags());      uint32_t exptime = htonl(it.getExptime());        itemId = (it.getId() <= 0) ? 1 : 0; And saw in the output: [ns_server:info,2012-08-28T12:40:24.368, n_0@127.0.0.1 :ns_port_memcached:ns_port_server:log:169]memcached<0.523.0>: Tue Aug 28 11:40:24.168302 3: FLAGS: 134217728 So it seems the Item class stores the flags (and expiration) in network byte order already, making the htonll conversion in couch-kvstore.cc unnecessary: https://github.com/couchbase/ep-engine/blob/master/src/couch-kvstore/couch-kvstore.cc#L248 Can you confirm me this analysis is correct? Also, same applies to expiration and CAS, right? thanks

Filipe Manana added a comment - 28/Aug/12 7:36 AM Also seems like expiration in item.hh is of type time_t, which on my platform is 64 bits (just a typedef of a long), but we only encode 32bits of it into the document revision. This together with the extra endianess conversion (if true), leads to cases where couchstore and view engine extract a 32 bits expiration time with all 4 bytes set to 0.

Chiyoung Seo added a comment - 28/Aug/12 12:32 PM Thanks Filipe for identifying this issue. Liang, can you please take a look at it?

Liang Guo added a comment - 28/Aug/12 8:21 PM Thanks to Filipe for giving a simple testcase to reproduce. The finding is - There is no redundant byte order conversion. When "flags" and "cas" are passed from memcached to ep-engine, they are in network byte order i.e. no conversion by memcached. So, en-engine stores them as is in network bye order. However, the code in CouchKVStore does the unnecessary htonl when creating CouchRequest, and ntohl when fetchDoc from couchstore. Tried removing byteorder conversion from CouchKVStore, then couch_dbdump shows correct flags value 8.

Filipe Manana added a comment - 29/Aug/12 6:17 AM Thanks. Due to my lack of familiarity with ep-engine, I was unsure if the problem was the extra htonl calls in the creation of CouchRequest or the Item class storing the fields in network byte order and not in the host's native byte order (this would probably have an impact in many places, and would have been noticed before). Either way, view-engine expects all the fields in the revision (CAS 64bits, flags 32bits, expiration 32bits) to be in network byte order.

Liang Guo added a comment - 29/Aug/12 11:44 AM Thanks for clarifying the view engine requirement. So, my understanding is that we need to save doc revision (CAS, flags, exptime) in network byteorder when persisting to couchstore. Currently, expiration time (exptime) is always ntohl converted when storing in ep-store, and it still need htonl conversion in COuchRequest. It was decided to store Item "flags" as is (i.e. network byte order) in ep-store, and that is why memcached_bin_update didn't fix byte order before calling ep-engine. Therefore, "flags" should not do htolnl conversion when the item is flushed. Same goes to "cas". However, there seems to be some confusion - memcached does conversion for tap_notify but not item_allocate, and ep-engine set_with_meta internally does conversion before storing them. Will cleanup all these.

Liang Guo added a comment - 30/Aug/12 7:12 PM Filipe, I agree that there is an issue with item metadata "flags" and I will add a fix. But, "flags" issue is not related to this bug. So, I verified expiration time with some trace dump. See exptime 111113 is same as in your testcase, and in ep-engine it is stored in host byte order 1346482114. >>> c.set("doc5",111113,8,"{\"address\": 8}") (3293123426, 49266116656, '') memcached<0.846.0>: Thu Aug 30 23:56:41.626064 3: DEBUG itemAllocate curtime 1346371001 exptime 111113 expiretime_ep-engine 1346482114 flags 134217728 memcached<0.846.0>: Thu Aug 30 23:56:41.626109 3: DEBUG nextCas 49266116656 memcached<0.846.0>: Thu Aug 30 23:56:41.626912 3: DEBUG CouchRequest getExptime_ep-engine 1346482114 exptime_network -1028701872 getFlags_ep-engine 134217728 flags_network 8 getCas_ep-engine 49266116656 cas_network 3479168666677805056 With couch_dbdump, expiry is same as expiretime_ep-engine in trace dump. So, it is correctly stored in network byte order while "flags" is not. Also, note that "cas" is correct as well. Couchbases-MacBook-Pro-8:default Liang$ ~/couchbase_dev_new/couchstore/.libs/couch_dbdump 0.couch.1 Doc seq: 1      id: doc5      rev: 1      content_meta: 0      cas: 49266116656, expiry: 1346482114, flags: 134217728      data: {"address": 8} Total docs: 1 So, I think this is probably not the root cause of the expiration issue in view engine. What do you think? I will create a separate bug for "flags" issue and have it fixed.

Filipe Manana added a comment - 30/Aug/12 7:18 PM Sounds good Liang. I never saw the expiration 0 issues actually, so it might not apply to master anymore, only noticed the flags one. I didn't go much further, but considered the chance of same issue in expiration and CAS as flags (wrong byte order). I think Iryna added very recently QE tests to verify the expiration values passed to views, and afaik there were no issues.

Chiyoung Seo added a comment - 30/Aug/12 7:25 PM As we don't see any inconsistency in expiration time in the latest build, closing this bug.