Problem:

  • Product: VisiBroker for C / Java
  • Component: VisiNotify
  • Version: 8 Service Pack 3
  • Platform: AIX5.3

Each Channel Admin can be configured with MaxQueueLength -- which is the maximum number of events that will be queued by the channel before the channel begins discarding events (according to the Discard Policy QoS parameter), or rejecting new events (depending on the setting of the RejectNewEvents admin property) upon receipt of each new event.

VisiNotify computes the high water mark level based on the given MaxQueueLength admin property.

The channel queue can reach the high water mark level or can even get full(MaxQueueLength), especially when supplier is sending events while consumer is not connected or is slower to consume the events. This depends on the scalability of the deployed system factoring in network, hardware, software configurations, and among others.

When there are too many events coming in from the supplier and the high water mark level is reached on the channel's queue, VisiNotify can be configured to delay the flow of incoming events from the supplier and allow the proxy supplier to de-queue the events to the consumers.

Resolution:

In order to delay the flow of incoming events from the supplier(proxy consumer) and yield the proxy supplier in sending out the events to connected consumers when the high water mark level is reached, you can set a time duration in milliseconds to vbroker.notify.channel.flowCtrlPause. This property will cause the proxy consumer to pause for the given time duration, while the proxy supplier will de-queue events to the consumers.

Here's a debug-level log snippet of VisiNotify:

1. While supplier keeps on sending events, at sometime, consumer was disconnected. Supplier will still send events and the current length starts to increase.

2. Before the high water mark level is reached, you will notice from VisiNotify logs that event gets queued without any pause:

Pid# 28754 Tim# Mon Oct 18 21:14:08 2010 953987ms Tid# 14 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 383 Lvl# DEBUG Msg# 4105:current length of queue is 3797 and discarded events count is 0
Pid# 28754 Tim# Mon Oct 18 21:14:08 2010 954556ms Tid# 14 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 383 Lvl# DEBUG Msg# 4105:current length of queue is 3798 and discarded events count is 0
Pid# 28754 Tim# Mon Oct 18 21:14:08 2010 955828ms Tid# 14 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 383 Lvl# DEBUG Msg# 4105:current length of queue is 3799 and discarded events count is 0
Pid# 28754 Tim# Mon Oct 18 21:14:08 2010 956417ms Tid# 14 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 383 Lvl# DEBUG Msg# 4105:current length of queue is 3800 and discarded events count is 0

3. When the high water mark level is reached (as computed by VisiNotify), you will notice this log snippet:

Pid# 28754 Tim# Mon Oct 18 21:14:26 2010 400950ms Tid# 45 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 383 Lvl# DEBUG Msg# 4105:current length of queue is 4130 and discarded events count is 0
Pid# 28754 Tim# Mon Oct 18 21:14:26 2010 400992ms Tid# 45 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 461 Lvl# INFO Msg# 4105:events in queue greater than high water mark
Pid# 28754 Tim# Mon Oct 18 21:14:26 2010 401033ms Tid# 45 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 509 Lvl# INFO Msg# 4105:added to queue

4. While the current length is equal or greater than high water mark level, notice the time pause between each queued event on the proxy consumer, in effect if the vbroker.notify.channel.flowCtrlPause is set. In this case, it was set to 10000 milliseconds:

Pid# 28754 Tim# Mon Oct 18 21:14:36 2010 411413ms Tid# 58 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 383 Lvl# DEBUG Msg# 4105:current length of queue is 4131 and discarded events count is 0
Pid# 28754 Tim# Mon Oct 18 21:14:46 2010 420850ms Tid# 71 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 383 Lvl# DEBUG Msg# 4105:current length of queue is 4132 and discarded events count is 0
Pid# 28754 Tim# Mon Oct 18 21:14:56 2010 430916ms Tid# 84 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 383 Lvl# DEBUG Msg# 4105:current length of queue is 4133 and discarded events count is 0
Pid# 28754 Tim# Mon Oct 18 21:15:06 2010 441159ms Tid# 97 Log# default Src# v_vnpxsup Fil# pushsup.C Lin# 383 Lvl# DEBUG Msg# 4105:current length of queue is 4134 and discarded events count is 0

5. If consumer is connected, the proxy supplier will have 10 seconds window period of de-queueing the events to the consumer. Depending on the context switching, eventually, the current length is decreased until it is below the high water mark. After the 10 seconds, the proxy consumer will again queue a new event and may once again reach the high water mark. Step #3 above will cyclically then be in effect.

If consumer is not at all connected, this property can delay reaching the 100% full on the channel's queue and give ample time for the user to check on disconnected consumer to ensure that events are not discarded or rejected.