Buffer Starvation?

JFrost
2014-01-29
2014-01-29
  • JFrost
    JFrost
    2014-01-29

    I hope I'm using the correct forum for this question.

    I originally found this problem running with Infinispan but the problem is easily reproduced with UUPerf.

    When I run UUPerf with a 4.5M data size and 10 RPCs I see the following error mixed randomly in the log:

    09:46:47.872 TRACE (Invoker-8) [org.jgroups.protocols.TP.down(TP.java:1296)] jfrost-multi-35669: sending msg to jfrost-multi2-12573,
    src=jfrost-multi-35669,
    headers are FRAG2: [id=32, frag_id=131, num_frags=226], UNICAST3: DATA, seqno=7087, conn_id=1, UDP: [channel_name=uuperf]
    

    I tracked in with the debugger and found the root cause is an IOException with the message "No buffers available".

    I can post trace logs if they will help. From the logs it also appears that the problem gets progressively worse as buffer problems will do. So it could be that once the error state is entered buffers don't get returned in a timely manner.

    At first I thought the problem was specifically the frag_size as the error seemed to occur at the frag_size boundary. For instance if I set frag_size=20K I would see errors with size 20082. But I was told by someone else that the size was normal(data+overhead).

    I've tried adjusting UDP buffers and max_bundle_size, FRAG2 frag_size and UFC/MFC max_credits and threshold. But I can't seem to find a magic combination of values that will alleviate the problem.

    Side question: When I get the error will the send be retried or is the update dropped? When I send 10 RPCs in UUPerf I still see a report for 10 updates on the receiving side even though I see 4 or 5 error reports.

    Any insights or suggestions are welcome.

    /Jack


    I'm running:

        2 nodes running FreeBSD hosted under VMWare.
        jgroups 3.4.1
        openjdk 1.7.0_25
    

    This is one of the last configurations I tried. With this config there seems to be a sensitivity to logging. With UDP set to DEBUG it only takes one 4.5M RPC to show the error. With TRACE it may not show up without raising the RPC count.

    <config xmlns="urn:org:jgroups"
            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
            xsi:schemaLocation="urn:org:jgroups http://www.jgroups.org/schema/JGroups-3.4.xsd">
       <UDP
             mcast_addr="${jgroups.udp.mcast_addr:228.6.7.8}"
             mcast_port="${jgroups.udp.mcast_port:46655}"
             tos="8"
             ucast_recv_buf_size="32m"
             ucast_send_buf_size="32m"
             mcast_recv_buf_size="32m"
             mcast_send_buf_size="32m"
             loopback="true"
             max_bundle_size="21k"
             ip_ttl="${jgroups.udp.ip_ttl:2}"
             enable_diagnostics="false"
             bundler_type="old"
    
             thread_naming_pattern="pl"
    
             thread_pool.enabled="true"
             thread_pool.min_threads="2"
             thread_pool.max_threads="30"
             thread_pool.keep_alive_time="60000"
             thread_pool.queue_enabled="true"
             thread_pool.queue_max_size="100"
             thread_pool.rejection_policy="Discard"
    
             oob_thread_pool.enabled="true"
             oob_thread_pool.min_threads="2"
             oob_thread_pool.max_threads="30"
             oob_thread_pool.keep_alive_time="60000"
             oob_thread_pool.queue_enabled="false"
             oob_thread_pool.queue_max_size="100"
             oob_thread_pool.rejection_policy="Discard"
    
             internal_thread_pool.enabled="true"
             internal_thread_pool.min_threads="1"
             internal_thread_pool.max_threads="10"
             internal_thread_pool.keep_alive_time="60000"
             internal_thread_pool.queue_enabled="true"
             internal_thread_pool.queue_max_size="100"
             internal_thread_pool.rejection_policy="Discard"
             />
    
       <PING timeout="3000" num_initial_members="3"/>
       <MERGE2 max_interval="30000" min_interval="10000"/>
    
       <FD_SOCK/>
       <FD_ALL timeout="15000" interval="3000"/>
       <VERIFY_SUSPECT timeout="1500"/>
    
       <pbcast.NAKACK2
                        xmit_interval="1000"
                        xmit_table_num_rows="100"
                        xmit_table_msgs_per_row="10000"
                        xmit_table_max_compaction_time="10000"
                        max_msg_batch_size="100"/>
       <UNICAST3
                  xmit_interval="500"
                  xmit_table_num_rows="20"
                  xmit_table_msgs_per_row="10000"
                  xmit_table_max_compaction_time="10000"
                  max_msg_batch_size="100"
                  conn_expiry_timeout="0"/>
    
       <pbcast.STABLE stability_delay="500" desired_avg_gossip="5000" max_bytes="1m"/>
       <pbcast.GMS print_local_addr="false" join_timeout="3000" view_bundling="true"/>
       <tom.TOA/> <!-- the TOA is only needed for total order transactions-->
    
       <UFC max_credits="2m" min_threshold="0.40" />
       <MFC max_credits="2m" min_threshold="0.40" />
       <FRAG2 frag_size="20k"  />
       <RSVP timeout="60000" resend_interval="500" ack_on_delivery="false" />  
    </config>