<div dir="ltr">I think I can explain the behavior I am observing.<div><br></div><div>rdkafka has a buffer (<span style="color:rgb(0,0,0);white-space:pre-wrap">queue.buffering.max.messages). I guess this buffer is drained by </span><span style="color:rgb(0,0,0);white-space:pre-wrap">rd_kafka_poll, which triggers delivery callback. </span></div><div><span style="color:rgb(0,0,0);white-space:pre-wrap">When kafka has a failure (spurious or otherwise) </span>_kafka_delivery_report_cb reinjects the message into the queue. The amount of messages reinjected can be very large, causing the queue to fill much faster than input log rate (depends on kafka timeout and max inflight requests I guess).</div><div>When the queue is full no further messages are inserted into the queue, i.e. syslog-ng drop counter increments and queue is stuck at max fifo size.</div><div>rd_kafka_poll is only called by _drain_responses, which is scheduled when messages are inserted into the queue.</div><div>Messages can't be inserted to the queue because the queue is full; Messages can't be drained from the rdkafka buffer because it's not possible to add new messages, and rd_kafka_poll is only scheduled on insert.</div><div><br></div><div><br></div><div>You can reproduce by setting queue.buffering.max.messages to 30 and log-fifo-size to 10. Stop kafka and log messages until the fifo fills up. All messages are dropped after this point. When you restart kafka rdkafka produce into kafka but syslog-ng never gets the delivery_cb because rd_kafka_poll isn't called.</div><div><br></div><div>I am not familiar with ivkis (or syslog-ng tbh) codebase but it seems the issue is that the timer is not scheduled because the worker is not scheduled. The only way I can see to fix is in the attached patch -- move the callback out of the worker and into mainloop. I know it's probably not ideal but it does seem to fix my issue.</div><div><br></div><div>I did try upgrading our ivykis version to 0.42.4 and it didn't seem to help.</div><div><br></div><div>Thanks,</div><div>John</div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Mon, Jan 13, 2020 at 9:53 AM Attila Szakacs (aszakacs) <<a href="mailto:Attila.Szakacs@oneidentity.com">Attila.Szakacs@oneidentity.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">




<div dir="ltr">
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0);background-color:rgb(255,255,255)">
Hi John,</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0);background-color:rgb(255,255,255)">
<br>
</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0);background-color:rgb(255,255,255)">
Could you gather debug logs with `syslog-ng -Fedtv`? It would provide a nice starting point.</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0);background-color:rgb(255,255,255)">
<br>
</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0);background-color:rgb(255,255,255)">
Thanks,</div>
<div style="font-family:Calibri,Arial,Helvetica,sans-serif;font-size:12pt;color:rgb(0,0,0);background-color:rgb(255,255,255)">
Attila</div>
<div id="gmail-m_599157910599484416appendonsend"></div>
<hr style="display:inline-block;width:98%">
<div id="gmail-m_599157910599484416divRplyFwdMsg" dir="ltr"><font face="Calibri, sans-serif" style="font-size:11pt" color="#000000"><b>From:</b> syslog-ng <<a href="mailto:syslog-ng-bounces@lists.balabit.hu" target="_blank">syslog-ng-bounces@lists.balabit.hu</a>> on behalf of John Skopis <<a href="mailto:jspam@skopis.com" target="_blank">jspam@skopis.com</a>><br>
<b>Sent:</b> Monday, January 13, 2020 10:11 AM<br>
<b>To:</b> <a href="mailto:syslog-ng@lists.balabit.hu" target="_blank">syslog-ng@lists.balabit.hu</a> <<a href="mailto:syslog-ng@lists.balabit.hu" target="_blank">syslog-ng@lists.balabit.hu</a>><br>
<b>Subject:</b> [syslog-ng] librdkafka and messages dropped</font>
<div> </div>
</div>
<div>
<div style="background-color:rgb(255,235,156);width:100%;border-style:solid;border-color:rgb(156,101,0);border-width:1pt;padding:2pt;font-size:10pt;line-height:12pt;font-family:Calibri;color:black;text-align:left">
<span style="color:rgb(156,101,0);font-weight:bold">CAUTION:</span> This email originated from outside of the organization. Do not follow guidance, click links, or open attachments unless you recognize the sender and know the content is safe.</div>
<br>
<div>
<div dir="ltr">Hello,
<div><br>
</div>
<div>We have a syslog-ng aggregator that accepts messages in a few different formats and logs the message format to kafka. The mapping looks something like:</div>
<div><br>
</div>
<div>format1 -> topic1</div>
<div>format2 -> topic2</div>
<div>...</div>
<div><br>
</div>
<div>Each agent will emit messages in ~4 different formats and send to the aggregator.</div>
<div>The aggregator is configured with a kafka_c destination with 8 threads/destination.</div>
<div><br>
</div>
<div>We were previously using the java kafka client without issue.</div>
<div>We recently upgraded to 3.24.1 + librdkafka 1.22</div>
<div><br>
</div>
<div>After upgrading we are seeing an issue where (seemingly randomly) syslog-ng stops producing messages into kafka.</div>
<div><br>
</div>
<div>Checking syslog-ng-ctl stats I can see</div>
<div>d_kafka_format1 has dropped message counter increasing</div>
<div>d_kafka_format1 queued messages counter increases to 80000 (10000*8 threads iw-size)<br>
</div>
<div>d_kafka_format1 processed messages does not increase</div>
<div><br>
</div>
<div>There are messages printed to the log that the destination queue is full for all of the rdkafka threads,</div>
<div><br>
</div>
<div>There are spurious failures to a kafka broker but it seems rdkafka reconnects.</div>
<div><br>
</div>
<div>Seems like once the destination queue becomes full syslog-ng never recovers and the instance must be restarted.</div>
<div>It also seems like rdkafka stops trying to reconnect to kafka (possibly?).</div>
<div><br>
</div>
<div>Is this expected behavior or is there some bug around reconnecting to kafka after a spurious timeout?</div>
<div>Just speculating here but does rdkafka stop trying to reconnect after N times? </div>
<div>Are there any examples of destroy/create destination client after failure thresholds?</div>
<div><br>
</div>
<div>Thanks</div>
<div><br>
</div>
</div>
</div>
</div>
</div>

______________________________________________________________________________<br>
Member info: <a href="https://lists.balabit.hu/mailman/listinfo/syslog-ng" rel="noreferrer" target="_blank">https://lists.balabit.hu/mailman/listinfo/syslog-ng</a><br>
Documentation: <a href="http://www.balabit.com/support/documentation/?product=syslog-ng" rel="noreferrer" target="_blank">http://www.balabit.com/support/documentation/?product=syslog-ng</a><br>
FAQ: <a href="http://www.balabit.com/wiki/syslog-ng-faq" rel="noreferrer" target="_blank">http://www.balabit.com/wiki/syslog-ng-faq</a><br>
<br>
</blockquote></div>