{"action":"created","issue":{"url":"https://api.github.com/repos/SnappyDataInc/snappy-store/issues/330","repository_url":"https://api.github.com/repos/SnappyDataInc/snappy-store","labels_url":"https://api.github.com/repos/SnappyDataInc/snappy-store/issues/330/labels{/name}","comments_url":"https://api.github.com/repos/SnappyDataInc/snappy-store/issues/330/comments","events_url":"https://api.github.com/repos/SnappyDataInc/snappy-store/issues/330/events","html_url":"https://github.com/SnappyDataInc/snappy-store/pull/330","id":265771547,"number":330,"title":"Snap 889","user":{"login":"vivekwiz","id":6355940,"avatar_url":"https://avatars1.githubusercontent.com/u/6355940?v=4","gravatar_id":"","url":"https://api.github.com/users/vivekwiz","html_url":"https://github.com/vivekwiz","followers_url":"https://api.github.com/users/vivekwiz/followers","following_url":"https://api.github.com/users/vivekwiz/following{/other_user}","gists_url":"https://api.github.com/users/vivekwiz/gists{/gist_id}","starred_url":"https://api.github.com/users/vivekwiz/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/vivekwiz/subscriptions","organizations_url":"https://api.github.com/users/vivekwiz/orgs","repos_url":"https://api.github.com/users/vivekwiz/repos","events_url":"https://api.github.com/users/vivekwiz/events{/privacy}","received_events_url":"https://api.github.com/users/vivekwiz/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":{"login":"suranjan","id":189977,"avatar_url":"https://avatars1.githubusercontent.com/u/189977?v=4","gravatar_id":"","url":"https://api.github.com/users/suranjan","html_url":"https://github.com/suranjan","followers_url":"https://api.github.com/users/suranjan/followers","following_url":"https://api.github.com/users/suranjan/following{/other_user}","gists_url":"https://api.github.com/users/suranjan/gists{/gist_id}","starred_url":"https://api.github.com/users/suranjan/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/suranjan/subscriptions","organizations_url":"https://api.github.com/users/suranjan/orgs","repos_url":"https://api.github.com/users/suranjan/repos","events_url":"https://api.github.com/users/suranjan/events{/privacy}","received_events_url":"https://api.github.com/users/suranjan/received_events","type":"User","site_admin":false},"assignees":[{"login":"suranjan","id":189977,"avatar_url":"https://avatars1.githubusercontent.com/u/189977?v=4","gravatar_id":"","url":"https://api.github.com/users/suranjan","html_url":"https://github.com/suranjan","followers_url":"https://api.github.com/users/suranjan/followers","following_url":"https://api.github.com/users/suranjan/following{/other_user}","gists_url":"https://api.github.com/users/suranjan/gists{/gist_id}","starred_url":"https://api.github.com/users/suranjan/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/suranjan/subscriptions","organizations_url":"https://api.github.com/users/suranjan/orgs","repos_url":"https://api.github.com/users/suranjan/repos","events_url":"https://api.github.com/users/suranjan/events{/privacy}","received_events_url":"https://api.github.com/users/suranjan/received_events","type":"User","site_admin":false},{"login":"vivekwiz","id":6355940,"avatar_url":"https://avatars1.githubusercontent.com/u/6355940?v=4","gravatar_id":"","url":"https://api.github.com/users/vivekwiz","html_url":"https://github.com/vivekwiz","followers_url":"https://api.github.com/users/vivekwiz/followers","following_url":"https://api.github.com/users/vivekwiz/following{/other_user}","gists_url":"https://api.github.com/users/vivekwiz/gists{/gist_id}","starred_url":"https://api.github.com/users/vivekwiz/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/vivekwiz/subscriptions","organizations_url":"https://api.github.com/users/vivekwiz/orgs","repos_url":"https://api.github.com/users/vivekwiz/repos","events_url":"https://api.github.com/users/vivekwiz/events{/privacy}","received_events_url":"https://api.github.com/users/vivekwiz/received_events","type":"User","site_admin":false}],"milestone":null,"comments":3,"created_at":"2017-10-16T13:32:49Z","updated_at":"2017-10-25T08:40:39Z","closed_at":null,"author_association":"NONE","pull_request":{"url":"https://api.github.com/repos/SnappyDataInc/snappy-store/pulls/330","html_url":"https://github.com/SnappyDataInc/snappy-store/pull/330","diff_url":"https://github.com/SnappyDataInc/snappy-store/pull/330.diff","patch_url":"https://github.com/SnappyDataInc/snappy-store/pull/330.patch"},"body":"## Changes proposed in this pull request\r\nFixes race between GII and an update going in parallel (As mentioned in point 2 below).\r\n\r\nThe scenario of defect is mentioned as below:\r\nPrimary Bucket:\r\n\r\n1. Gets update operation:\r\nstoregemfire1_5242/system-01-01.log : \r\n17/10/12 09:42:11.663 IST Function Execution Processor12<tid=0x2b4> INFO storegemfire1_localhost_5242: QueryDistribution: GS#prepMinion: preparing update trade.securities set exchange =? where sec_id = ? and tid = ?\r\n\r\n2. Sends to Secondary, secondary enqueues the delta. But, at the end of GII it is not applied to the oldValue as seen from the log. We think the delta value corresponding to update came after requestForDelta is done. There is race condition between update and GII.\r\nThe node goes down after 25 seconds.\r\n\r\n\r\nstoregemfire1_21727/system-01-01.log\r\n17/10/12 09:42:11.646 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x1a8> INFO storegemfire1_localhost_21727: Region _B__TRADE_SECURITIES_110 requesting initial image from 192.168.1.164(storegemfire1_localhost_5242:5242)<v21>:6902\r\n\r\n17/10/12 09:42:11.669 IST P2P message reader for 192.168.1.164(storegemfire1_localhost_5242:5242)<v21>:6902 unshared ordered uid=32 dom #2<tid=0x11c> INFO storegemfire1_localhost_21727: enqueDelta: new list of deltas with delta: SerializableDelta@0x63581f25: changedRow= col[0]=null col[1]=null col[2]=null col[3]=tse col[4]=null, validColumns=(3)for re =VersionedBucketRowLocationThinDiskRegionEntryHeap@8cb6d38(key=(825); rawValue=(2,0,0,3,57,112,119,122,109,118,53,20,1,65,54,-6,-114,59,-102,-19,-122,-96,102,115,101,0,0,0,5,5,11,22,25); lockState=0x0; bucketId=110) oldVal = [B@429fb399\r\n\r\n\r\n\r\n17/10/12 09:42:11.690 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x1a8> INFO storegemfire1_localhost_21727: recording rv0 for 1db6baf6-3d8e-4c62-b27c-1943280b3713 rvv {7e630fd5-4c7a-4f66-8542-1bf92ce1dda4={rv18 bsv1 bs=[], 1db6baf6-3d8e-4c62-b27c-1943280b3713={rv28 bsv1 bs=[]} contains true\r\n\r\n17/10/12 09:42:11.695 IST P2P message reader for 192.168.1.164(storegemfire1_localhost_5242:5242)<v21>:6902 unshared ordered uid=32 dom #2<tid=0x11c> INFO storegemfire1_localhost_21727: recording rv19 for 7e630fd5-4c7a-4f66-8542-1bf92ce1dda4 rvv {7e630fd5-4c7a-4f66-8542-1bf92ce1dda4={rv19 bsv18 bs=[0,1], 1db6baf6-3d8e-4c62-b27c-1943280b3713={rv28 bsv1 bs=[]} contains true\r\n\r\n\r\n3. Secondary restarts: comes up with rv 18. It missed the ListOfDelta value related to the updated entry. It comes up with oldValue and earlier regionversion.\r\n17/10/12 09:42:42.123 IST vm_3_thr_18_store1_localhost_21727<tid=0x303> INFO storegemfire1_localhost_21727:\r\n17/10/12 09:42:42.123 IST vm_3_thr_18_store1_localhost_21727<tid=0x303> INFO storegemfire1_localhost_21727:\r\n17/10/12 09:43:03.898 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x4cf> INFO storegemfire1_localhost_21727: Initializing region _B__TRADE_SECURITIES_110\r\n17/10/12 09:43:03.898 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x4cf> INFO storegemfire1_localhost_21727: recording rv28 for 1db6baf6-3d8e-4c62-b27c-1943280b3713 rvv {7e630fd5-4c7a-4f66-8542-1bf92ce1dda4={rv18 bsv18 bs=[0], 1db6baf6-3d8e-4c62-b27c-1943280b3713={rv28 bsv1 bs=[]} contains true\r\n\r\n\r\n4. Primary restarts, comes up with rv 19, concludes the rv19 to be unfinished operation and rejects the updated entry. After GII, both primary and secondary have rv18 as latest region version.\r\n17/10/12 09:42:42.126 IST vm_6_thr_21_store1_localhost_5242<tid=0x33e> INFO storegemfire1_localhost_5242:\r\n\r\n17/10/12 09:43:03.973 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x4db> INFO storegemfire1_localhost_5242: recording rv19 for 7e630fd5-4c7a-4f66-8542-1bf92ce1dda4 rvv {7e630fd5-4c7a-4f66-8542-1bf92ce1dda4={rv19 bsv1 bs=[], 1db6baf6-3d8e-4c62-b27c-1943280b3713={rv28 bsv1 bs=[]} contains true\r\n\r\n\r\n17/10/12 09:43:03.973 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x4db> INFO storegemfire1_localhost_5242: Region:/__PR/_B__TRADE_SECURITIES_110 found unfinished operation key=tableinfo(true).CompactCompositeRegionKey@40e6f85e=(825),member=7e630fd5-4c7a-4f66-8542-1bf92ce1dda4,region version=19\r\n\r\n\r\n17/10/12 09:43:03.978 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x4db> INFO storegemfire1_localhost_5242: Region /__PR/_B__TRADE_SECURITIES_110 recovered with EndGII flag, rvv is RegionVersionVector[7e630fd5-4c7a-4f66-8542-1bf92ce1dda4={rv19 gc0 localVersion=19 local exceptions=[]} others={7e630fd5-4c7a-4f66-8542-1bf92ce1dda4={rv19 bsv1 bs=[], 1db6baf6-3d8e-4c62-b27c-1943280b3713={rv28 bsv28 bs=[0]}, gc={}]. recovered rvv is RegionVersionVector[7e630fd5-4c7a-4f66-8542-1bf92ce1dda4={rv19 gc0 localVersion=19 local exceptions=[]} others={7e630fd5-4c7a-4f66-8542-1bf92ce1dda4={rv19 bsv1 bs=[], 1db6baf6-3d8e-4c62-b27c-1943280b3713={rv28 bsv28 bs=[0]}, gc={}]. Do delta GII\r\n\r\n17/10/12 09:43:04.000 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x4db> INFO storegemfire1_localhost_5242: Processing unfinished operation:entry=VersionedBucketRowLocationThinDiskRegionEntryHeap@3a3102f6(key=(825); rawValue=(2,0,0,3,57,112,119,122,109,118,53,20,1,65,54,-6,-114,59,-102,-19,-122,-96,102,115,101,0,0,0,5,5,11,22,25); lockState=0x0; bucketId=110)\r\n17/10/12 09:43:04.000 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x4db> INFO storegemfire1_localhost_5242: _B__TRADE_SECURITIES_110 is done getting image from 192.168.1.164(storegemfire1_localhost_21727:21727)<v28>:9371. isDeltaGII is true rvv is RegionVersionVector{rv19 gc0}\r\n17/10/12 09:43:04.000 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x4db> INFO storegemfire1_localhost_5242: Region _B__TRADE_SECURITIES_110 initialized persistent id: /192.168.1.164:/home/vivek/work/bugs/1689/hydra/hydraLogs/sqlDisk/2017-10-11-19-56-36/randomPartitionReplPersistTablesHA-1012-092757/vm_6_store1_disk/persistSecu created at timestamp 1507781569942 version 0 diskStoreId 7e630fd5-4c7a-4f66-8542-1bf92ce1dda4 name null with data from 192.168.1.164(storegemfire1_localhost_21727:21727)<v28>:9371.\r\n17/10/12 09:43:04.000 IST Recovery thread for bucket _B__TRADE_SECURITIES_110<tid=0x4db> INFO storegemfire1_localhost_5242: recording rv0 for 7e630fd5-4c7a-4f66-8542-1bf92ce1dda4 rvv {7e630fd5-4c7a-4f66-8542-1bf92ce1dda4={rv19 bsv1 bs=[][e(n=20 p=18; rb=[])], 1db6baf6-3d8e-4c62-b27c-1943280b3713={rv28 bsv1 bs=[]} contains true\r\n \r\n\r\n## Patch testing\r\nHydra test\r\nPrecheckin\r\n\r\n## ReleaseNotes changes\r\nNo\r\n\r\n## Other PRs \r\nNo\r\n"},"comment":{"url":"https://api.github.com/repos/SnappyDataInc/snappy-store/issues/comments/339257994","html_url":"https://github.com/SnappyDataInc/snappy-store/pull/330#issuecomment-339257994","issue_url":"https://api.github.com/repos/SnappyDataInc/snappy-store/issues/330","id":339257994,"user":{"login":"sumwale","id":11540628,"avatar_url":"https://avatars3.githubusercontent.com/u/11540628?v=4","gravatar_id":"","url":"https://api.github.com/users/sumwale","html_url":"https://github.com/sumwale","followers_url":"https://api.github.com/users/sumwale/followers","following_url":"https://api.github.com/users/sumwale/following{/other_user}","gists_url":"https://api.github.com/users/sumwale/gists{/gist_id}","starred_url":"https://api.github.com/users/sumwale/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/sumwale/subscriptions","organizations_url":"https://api.github.com/users/sumwale/orgs","repos_url":"https://api.github.com/users/sumwale/repos","events_url":"https://api.github.com/users/sumwale/events{/privacy}","received_events_url":"https://api.github.com/users/sumwale/received_events","type":"User","site_admin":false},"created_at":"2017-10-25T08:40:38Z","updated_at":"2017-10-25T08:40:38Z","author_association":"NONE","body":"Ok, got the scenario. Won't it be better to set a flag on ImageState instead? Before the call to requestUnappliedDeltas set a flag, and then the incoming puts will check that flag instead of owner.initiailzed (can see the checks in AbstractRegionMap.enqueDelta, HDFSRegionMapDelegate.getValueDuringGII). One would need to make ImageState.addDeltaEntry as returning a boolean to add only if that flag is not set atomically and only then rest of method should follow. Perhaps that call should go inside listOfDeltasCreator.\r\n\r\nQuite apprehensive about the cross-module read-write lock approach. Still can see paths where lock/unlock can mismatch."}}
{"actor":{"display_login":"sumwale"}}