A consumer shuts down not cleanly

[yse]

Description

It's seems that consumer->close() do not correctly shuts down consumer. Rebalance of consumer group occurs only after session timeout.

How to reproduce

1. Download 0.11.5 release
2. Unpack it
3. Build it (cmake, make)
4. Run rdkafka_consumer_example_cpp as follow:

./rdkafka_consumer_example_cpp -g test_group Topic

5. Run yet another rdkafka_consumer_example_cpp with same group:

./rdkafka_consumer_example_cpp -g test_group Topic

6. Logs of the first:

% Created consumer rdkafka#consumer-1
RebalanceCb: Local: Assign partitions: Topic[0], Topic[1], Topic[2], Topic[3], Topic[4], 

Logs of the second:

% Consumer group rebalanced: assigned:
 Topic [5] offset -1001, Topic [6] offset -1001, Topic [7] offset -1001, Topic [8] offset -1001, Topic [9] offset -1001

while it's seems ok
7. Stop one of the consumer (Ctrl-C). Logs:

% Consumer group rebalanced: revoked:
 Topic [5] offset -1001, Topic [6] offset -1001, Topic [7] offset -1001, Topic [8] offset -1001, Topic [9] offset -1001

8. Only after 30 seconds (default session.timeout.ms) in another consumer appears rebalance callbacks logs:

RebalanceCb: Local: Revoke partitions: Topic[0], Topic[1], Topic[2], Topic[3], Topic[4], 
RebalanceCb: Local: Assign partitions: Topic[0], Topic[1], Topic[2], Topic[3], Topic[4], Topic[5], Topic[6], Topic[7], Topic[8], Topic[9],

Note: same behavior in c-client

Checklist

• librdkafka version (release number or git tag): 0.11.5
• Apache Kafka version: 0.10.0.1
• librdkafka client configuration: as in examples
• Operating system: Ubuntu 16.04 (x64)
• Provide logs (with debug=.. as necessary) from librdkafka
• Provide broker log excerpts
• Critical issue

[edenhill]

Use -d protocol to see if a LeaveGroupRequest is sent by the departing client.

[yse]

Yes, the request was sent but another consumer

2018-09-18 14:44:01.977: LOG-7-SEND: [thrd: localhost:9092/bootstrap]: localhost:9092/0: Sent LeaveGroupRequest (v0, 79 bytes @ 0, CorrId 165)

But unfortunately rebalance occurs after 30 seconds by SyncGroupResponse

2018-09-18 14:44:31.818: LOG-7-RECV: [thrd:localhost:9092/bootstrap]: localhost:9092/0: Received SyncGroupResponse (v0, 67 bytes, CorrId 549, rtt 5.99ms)
RebalanceCb: Local: Assign partitions: Topic[0], Topic[1], Topic[2], Topic[3], Topic[4], Topic[5], Topic[6], Topic[7], Topic[8], Topic[9],

See on time 14:44:01.977 and 14:44:31.818

Note: If I'm connecting to the consumer group id by python client (aiokafka) - there are no problems on join or leave the group. Rebalnce callback occurs in time it's happens

[yse]

Full logs also attached:
consumer-1.log
consumer-departing.log

[edenhill]

Thank you!

It seems like the LeaveGroupRequest is enqueued for transmission but the consumer is shut down before the request is actually sent to the broker.
I'll fix it, as a workaround you can add a sleep(1) after the consumer->close() call

[edenhill]

Related to #2040