{"action":"created","issue":{"url":"https://api.github.com/repos/grpc/grpc/issues/15947","repository_url":"https://api.github.com/repos/grpc/grpc","labels_url":"https://api.github.com/repos/grpc/grpc/issues/15947/labels{/name}","comments_url":"https://api.github.com/repos/grpc/grpc/issues/15947/comments","events_url":"https://api.github.com/repos/grpc/grpc/issues/15947/events","html_url":"https://github.com/grpc/grpc/pull/15947","id":339079505,"node_id":"MDExOlB1bGxSZXF1ZXN0MTk5ODUzNTI1","number":15947,"title":"Fixed ordering in adding pending picks to RR","user":{"login":"dgquintas","id":120217,"node_id":"MDQ6VXNlcjEyMDIxNw==","avatar_url":"https://avatars3.githubusercontent.com/u/120217?v=4","gravatar_id":"","url":"https://api.github.com/users/dgquintas","html_url":"https://github.com/dgquintas","followers_url":"https://api.github.com/users/dgquintas/followers","following_url":"https://api.github.com/users/dgquintas/following{/other_user}","gists_url":"https://api.github.com/users/dgquintas/gists{/gist_id}","starred_url":"https://api.github.com/users/dgquintas/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/dgquintas/subscriptions","organizations_url":"https://api.github.com/users/dgquintas/orgs","repos_url":"https://api.github.com/users/dgquintas/repos","events_url":"https://api.github.com/users/dgquintas/events{/privacy}","received_events_url":"https://api.github.com/users/dgquintas/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":20,"created_at":"2018-07-06T21:43:30Z","updated_at":"2018-07-10T21:40:55Z","closed_at":null,"author_association":"MEMBER","pull_request":{"url":"https://api.github.com/repos/grpc/grpc/pulls/15947","html_url":"https://github.com/grpc/grpc/pull/15947","diff_url":"https://github.com/grpc/grpc/pull/15947.diff","patch_url":"https://github.com/grpc/grpc/pull/15947.patch"},"body":"Otherwise we may try to drain the pending picks _before_ the pending pick has been added. \r\n\r\nIf READY subchannels are being recycled (for instance, if channels against the same target/addresses are being created and destroyed in a loop), the RR LB policy of a new channel will pick these subchannels in READY state. However, prior to this fix, `DrainPendingPicksLocked` was called _before_ the pending pick is registered: only connectivity state _transitions_ would cause the pending picks to be reprocessed. Which is why things seemed to work, as in most cases, an LB policy (and its subchannels) would start in a state other than READY and then transition into it.\r\n\r\nConsider (with extra logging and whitespace added for clarity):\r\n\r\n```\r\nI0706 13:52:28.572841742  206522 round_robin.cc:358]         [RR 0x7fdd5c004790] Trying to pick (shutdown: 0)\r\n\r\n// The following block encompases DoPick\r\nI0706 13:52:28.572850644  206522 round_robin.cc:362]         [RR 0x7fdd5c004790] XXX before DoPick\r\nI0706 13:52:28.572868100  206522 round_robin.cc:555]         [RR 0x7fdd5c004790] getting next ready subchannel (out of 2), last_ready_index=18446744073709551615\r\nI0706 13:52:28.572882302  206522 round_robin.cc:564]         [RR 0x7fdd5c004790] checking subchannel 0x7fdd5c005f90, subchannel_list 0x7fdd5c006d50, index 0: state=IDLE\r\nI0706 13:52:28.572892832  206522 round_robin.cc:564]         [RR 0x7fdd5c004790] checking subchannel 0x7fdd5c006930, subchannel_list 0x7fdd5c006d50, index 1: state=IDLE\r\nI0706 13:52:28.572898391  206522 round_robin.cc:582]         [RR 0x7fdd5c006d50] no subchannels in ready state\r\nI0706 13:52:28.572923655  206522 round_robin.cc:364]         [RR 0x7fdd5c004790] XXX after DoPick\r\n\r\n\r\n// The following encompases what happens after DoPick() has returned false,\r\n// indiating an async pick.\r\n\r\nI0706 13:52:28.572929421  206522 round_robin.cc:366]         [RR 0x7fdd5c004790] YYY before adding pick to pending_picks_=(nil)\r\nI0706 13:52:28.572938257  206522 connectivity_state.cc:92]   CONWATCH: 0x7fdd5c0060b0 subchannel: get READY\r\nI0706 13:52:28.573123261  206522 round_robin.cc:508]         [RR 0x7fdd5c004790] connectivity changed for subchannel 0x7fdd5c005f90, subchannel_list 0x7fdd5c006d50 (index 0 of 2): prev_state=IDLE new_state=READ\r\nY\r\nI0706 13:52:28.573133577  206522 connectivity_state.cc:92]   CONWATCH: 0x7fdd5c006a50 subchannel: get READY\r\nI0706 13:52:28.573141425  206522 round_robin.cc:508]         [RR 0x7fdd5c004790] connectivity changed for subchannel 0x7fdd5c006930, subchannel_list 0x7fdd5c006d50 (index 1 of 2): prev_state=IDLE new_state=READ\r\nY\r\n\r\n// At this point, we try to process pending picks, but note no pending pick has\r\n// been added yet.\r\n\r\nI0706 13:52:28.573148090  206522 round_robin.cc:344]         [RR 0x7fdd5c004790] XXX DrainPendingPicksLocked pending_picks_=(nil) \r\nI0706 13:52:28.573182049  206522 connectivity_state.cc:164]  SET: 0x7fdd5c0047e8 round_robin: IDLE --> READY [rr_ready] error=(nil) \"No Error\"\r\nI0706 13:52:28.573187842  206522 connectivity_state.cc:190]  NOTIFY: 0x7fdd5c0047e8 round_robin: 0x7fdd5c002ce8\r\nI0706 13:52:28.573207063  206522 subchannel_list.h:292]      [round_robin 0x7fdd5c004790] subchannel list 0x7fdd5c006d50 index 0 of 2 (subchannel 0x7fdd5c005f90): starting watch: requesting connectivity change \r\nnotification (from READY)\r\nI0706 13:52:28.573250859  206522 subchannel_list.h:292]      [round_robin 0x7fdd5c004790] subchannel list 0x7fdd5c006d50 index 1 of 2 (subchannel 0x7fdd5c006930): starting watch: requesting connectivity change notification (from READY)\r\n\r\n// It is at this point that the pending pick is registered, by the attempt to\r\n// drain the pending picks has already happened and the policy is READY, which\r\n// means the (pending) pick will stall until something else happens to the\r\n// subchannels/policy (eg. disconnection).\r\nI0706 13:52:28.573297056  206522 round_robin.cc:373]         [RR 0x7fdd5c004790] YYY after adding pick to pending_picks_=0x7fdd680266f8\r\n```\r\n\r\nFixes #15892"},"comment":{"url":"https://api.github.com/repos/grpc/grpc/issues/comments/403975147","html_url":"https://github.com/grpc/grpc/pull/15947#issuecomment-403975147","issue_url":"https://api.github.com/repos/grpc/grpc/issues/15947","id":403975147,"node_id":"MDEyOklzc3VlQ29tbWVudDQwMzk3NTE0Nw==","user":{"login":"dgquintas","id":120217,"node_id":"MDQ6VXNlcjEyMDIxNw==","avatar_url":"https://avatars3.githubusercontent.com/u/120217?v=4","gravatar_id":"","url":"https://api.github.com/users/dgquintas","html_url":"https://github.com/dgquintas","followers_url":"https://api.github.com/users/dgquintas/followers","following_url":"https://api.github.com/users/dgquintas/following{/other_user}","gists_url":"https://api.github.com/users/dgquintas/gists{/gist_id}","starred_url":"https://api.github.com/users/dgquintas/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/dgquintas/subscriptions","organizations_url":"https://api.github.com/users/dgquintas/orgs","repos_url":"https://api.github.com/users/dgquintas/repos","events_url":"https://api.github.com/users/dgquintas/events{/privacy}","received_events_url":"https://api.github.com/users/dgquintas/received_events","type":"User","site_admin":false},"created_at":"2018-07-10T21:40:55Z","updated_at":"2018-07-10T21:40:55Z","author_association":"MEMBER","body":"Maybe \"recycle\" isn't the right word. Yes, we use the same subchannel, which stays READY the whole time. Reuse is probably a better description."}}
{"actor":{"display_login":"dgquintas"}}