Assertion `!*"refcnt sub-zero"' after reconnect

[matthrae]

Description

After a disconnect and reconnected (after min 1h) I got this Assertion. Not at each try but very often.
rd_refcnt_sub0: Assertion `!*"refcnt sub-zero"' failed

I try to analyse with memcheck, see output in logfile below.

-Release-Version 0.11.6 and C interface, compiled with 32bit
-OpenSuse 42.1 64bit
-Application is running with root privileges
-Default-Configuration
-Apache Kafka-Version: ???

How to reproduce

cut connection to server for minimum 1h and reconnect

[matthrae]

assert_refcntsub-zero.txt

[matthrae]

Backtrace of gdb:
#0 0xf7fd9f89 in __kernel_vsyscall ()
#1 0xf7c228e7 in raise () from /lib/libc.so.6
#2 0xf7c24065 in abort () from /lib/libc.so.6
#3 0xf7c1b6d7 in __assert_fail_base () from /lib/libc.so.6
#4 0xf7c1b787 in __assert_fail () from /lib/libc.so.6
#5 0x0804efad in rd_refcnt_sub0 (R=) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rd.h:308
#6 0x0826fe08 in rd_refcnt_sub0 (R=) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_partition.c:1332
#7 rd_kafka_topic_partition_destroy0 (do_free=, rktpar=) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_partition.c:2524
#8 rd_kafka_topic_partition_list_destroy (rktparlist=) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_partition.c:2545
#9 rd_kafka_toppar_handle_Offset (rk=0xf350ac80, rkb=0xf350bc68, err=, rkbuf=0xf0a01ef8, request=0xf342ebe8, opaque=0xf3503fa0) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_partition.c:1281
#10 0x0823ae1a in rd_kafka_buf_callback (rk=0xf350ac80, rkb=0xf350bc68, err=RD_KAFKA_RESP_ERR__DESTROY, response=0xf0a01ef8, request=0xf342ebe8) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_buf.c:448
#11 0x0823b7fc in rd_kafka_buf_handle_op (rko=0xf0a019d0, err=RD_KAFKA_RESP_ERR__DESTROY) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_buf.c:397
#12 0x082616ad in rd_kafka_op_destroy (rko=0xf0a019d0) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_op.c:280
#13 0x08262241 in rd_kafka_op_reply (rko=0xf0a019d0, err=RD_KAFKA_RESP_ERR__DESTROY) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_op.c:433
#14 0x0823b156 in rd_kafka_q_enq1 (at_head=0, do_lock=1, orig_destq=, rko=0xf0a019d0, rkq=) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_queue.h:372
#15 rd_kafka_q_enq (rko=0xf0a019d0, rkq=) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_queue.h:413
#16 rd_kafka_replyq_enq (version=0, rko=0xf0a019d0, replyq=0xf342ec5c) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_queue.h:707
#17 rd_kafka_buf_callback (rk=0xf350ac80, rkb=0xf350bc68, err=RD_KAFKA_RESP_ERR_NO_ERROR, response=0xf0a01ef8, request=0xf342ebe8) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_buf.c:441
#18 0x08230349 in rd_kafka_req_response (rkbuf=0xf0a01ef8, rkb=) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_broker.c:1309
#19 rd_kafka_recv (rkb=0xf350bc68) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_broker.c:1421
#20 0x082a6049 in rd_kafka_transport_io_event (rktrans=rktrans@entry=0xf0a094d8, events=1) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_transport.c:1434
#21 0x082a6b2c in rd_kafka_transport_io_serve (rktrans=0xf0a094d8, timeout_ms=999) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_transport.c:1481
#22 0x08235cd1 in rd_kafka_broker_serve (rkb=rkb@entry=0xf350bc68, abs_timeout=) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_broker.c:2555
#23 0x08238026 in rd_kafka_broker_consumer_serve (rkb=0xf350bc68) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_broker.c:3463
#24 rd_kafka_broker_thread_main (arg=0xf350bc68) at ../../../Source/Runtime/../Extern/rdkafka_c/src/rdkafka_broker.c:3575
#25 0xf7e0c484 in start_thread () from /lib/libpthread.so.0
#26 0xf7ce45be in clone () from /lib/libc.so.6

[edenhill]

👍 on running with valgrind, and gdb!

[edenhill]

Are you creating any rd_kafka_topic_t objects? (thru rd_kafka_topic_new())
And if so; are you destroying them prior to terminating the client? Make sure that the new() and destroy() are symmetrical, one destroy for each new

[matthrae]

Sorry for late answer
My Program:
first I create one producer and one consumer
then I create four topics and start each and consume each periodically
then I create four topics and produce periodically
after consuming I destroy messages only
When stopping the application topics and producer/consumer are destroyed

Probably I found the reason for the problem:
during main loop I stop the consumer after "brokers down message" and start it again
when first value is comsumed program sometimes crashed

After removing stop and start command from main loop the program does not crash for many days

[edenhill]

Sorry for the slow reply, could you try reproducing this on master?
There's been alot of improvements and fixes since v0.11.6.