added logging to hpack

jetty-http2/http2-hpack/src/main/java/org/eclipse/jetty/http2/hpack/HpackContext.java

@@ -31,12 +31,15 @@ import org.eclipse.jetty.http.HttpMethod;
 import org.eclipse.jetty.http.HttpScheme;
 import org.eclipse.jetty.util.ArrayQueue;
 import org.eclipse.jetty.util.ArrayTernaryTrie;
-import org.eclipse.jetty.util.ArrayTrie;
 import org.eclipse.jetty.util.StringUtil;
 import org.eclipse.jetty.util.Trie;
+import org.eclipse.jetty.util.log.Log;
+import org.eclipse.jetty.util.log.Logger;
 
 public class HpackContext
 {
+    public static final Logger LOG = Log.getLogger(HpackContext.class);
+    
     public static final String[][] STATIC_TABLE = 
     {
         {null,null},
@@ -182,6 +185,7 @@ public class HpackContext
     
     public void resize(int maxHeaderTableSize)
     {
+        LOG.debug("HdrTbl resized {}",maxHeaderTableSize);
         _maxHeaderTableSizeInBytes=maxHeaderTableSize;
         int guesstimateEntries = 10+maxHeaderTableSize/(32+10+10);
         evict();
@@ -223,12 +227,16 @@ public class HpackContext
         Entry entry=new Entry(i,field);
         int size = entry.getSize();
         if (size>_maxHeaderTableSizeInBytes)
+        {
+            LOG.debug("!added {} too big",field);
             return null;
+        }
         _headerTableSizeInBytes+=size;
         _headerTable.addUnsafe(entry);
         _fieldMap.put(field,entry);
         _nameMap.put(StringUtil.asciiToLowerCase(field.getName()),entry);
 
+        LOG.debug("HdrTbl added {}",entry);
         evict();
         return entry;
     }
@@ -249,6 +257,7 @@ public class HpackContext
     
     public void addToRefSet(Entry entry)
     {
+        LOG.debug("RefSet added {}",entry);
         entry.addToRefSet(this);
     }
     
@@ -259,6 +268,7 @@ public class HpackContext
     
     public void clearReferenceSet()
     {
+        LOG.debug("RefSet cleared");
         Entry entry = _refSet._refSetNext;
         while(entry!=_refSet)
         {
@@ -280,6 +290,7 @@ public class HpackContext
                 entry._used=false;
             else
             {
+                LOG.debug("RefSet remove unused {}",entry);
                 // encode the reference to remove it
                 buffer.put((byte)0x80);
                 NBitInteger.encode(buffer,7,index(entry));
@@ -297,7 +308,10 @@ public class HpackContext
             if (entry.isUsed())
                 entry._used=false;
             else
+            {
+                LOG.debug("RefSet emit unused {}",entry);
                 builder.emit(entry.getHttpField());
+            }
             
             entry=entry._refSetNext;
         }
@@ -342,6 +356,7 @@ public class HpackContext
         while (_headerTableSizeInBytes>_maxHeaderTableSizeInBytes)
         {
             Entry entry = _headerTable.pollUnsafe();
+            LOG.debug("HdrTbl evict {}",entry);
             _headerTableSizeInBytes-=entry.getSize();
             entry.removeFromRefSet();
             entry._index=-1;
@@ -460,6 +475,7 @@ public class HpackContext
             _refSetPrev=ctx._refSet._refSetPrev;
             ctx._refSet._refSetPrev._refSetNext=this;
             ctx._refSet._refSetPrev=this;
+            LOG.debug("RefSet add {}",this);
         }
 
         public boolean isInReferenceSet()
@@ -469,6 +485,7 @@ public class HpackContext
         
         public void removeFromRefSet()
         {
+            LOG.debug("RefSet remove {}",this);
             if (_refSetNext!=this)
             {
                 _refSetNext._refSetPrev=_refSetPrev;

jetty-http2/http2-hpack/src/main/java/org/eclipse/jetty/http2/hpack/HpackDecoder.java

@@ -26,6 +26,9 @@ import org.eclipse.jetty.http.HttpHeader;
 import org.eclipse.jetty.http.HttpMethod;
 import org.eclipse.jetty.http.HttpScheme;
 import org.eclipse.jetty.http2.hpack.HpackContext.Entry;
+import org.eclipse.jetty.util.TypeUtil;
+import org.eclipse.jetty.util.log.Log;
+import org.eclipse.jetty.util.log.Logger;
 
 
 /* ------------------------------------------------------------ */
@@ -34,6 +37,8 @@ import org.eclipse.jetty.http2.hpack.HpackContext.Entry;
  */
 public class HpackDecoder
 {
+    public static final Logger LOG = Log.getLogger(HpackDecoder.class);
+    
     private final HpackContext _context;
     private final MetaDataBuilder _builder = new MetaDataBuilder();
 
@@ -48,10 +53,15 @@ public class HpackDecoder
     }
     
     public MetaData decode(ByteBuffer buffer)
-    {
+    {           
-                
         while(buffer.hasRemaining())
         {
+            if (LOG.isDebugEnabled())
+            {
+                int l=Math.min(buffer.remaining(),16);
+                LOG.debug("decode  "+TypeUtil.toHexString(buffer.array(),buffer.arrayOffset()+buffer.position(),l)+(l<buffer.remaining()?"...":""));
+            }
+            
             byte b = buffer.get();
             if (b<0)
             {
@@ -62,6 +72,7 @@ public class HpackDecoder
                     _context.get(index).removeFromRefSet();
                 else if (entry.isStatic())
                 {
+                    LOG.debug("decode IdxStatic {}",entry);
                     // emit field
                     _builder.emit(entry.getHttpField());
                     
@@ -72,6 +83,7 @@ public class HpackDecoder
                 }
                 else
                 {
+                    LOG.debug("decode Idx {}",entry);
                     // emit
                     _builder.emit(entry.getHttpField());
                     // add to reference set
@@ -91,6 +103,7 @@ public class HpackDecoder
                     // literal 
                     boolean indexed=f>=4;
                     int bits=indexed?6:4;
+                    boolean huffmanName=false;
                     
                     // decode the name
                     int name_index=NBitInteger.decode(buffer,bits);
@@ -102,9 +115,9 @@ public class HpackDecoder
                     }
                     else
                     {
-                        boolean huffman = (buffer.get()&0x80)==0x80;
+                        huffmanName = (buffer.get()&0x80)==0x80;
                         int length = NBitInteger.decode(buffer,7);
-                        if (huffman)
+                        if (huffmanName)
                             name=Huffman.decode(buffer,length);
                         else
                             name=toASCIIString(buffer,length);
@@ -112,9 +125,9 @@ public class HpackDecoder
                     }
                     
                     // decode the value
-                    boolean huffman = (buffer.get()&0x80)==0x80;
+                    boolean huffmanValue = (buffer.get()&0x80)==0x80;
                     int length = NBitInteger.decode(buffer,7);
-                    if (huffman)
+                    if (huffmanValue)
                         value=Huffman.decode(buffer,length);
                     else
                         value=toASCIIString(buffer,length);
@@ -132,7 +145,7 @@ public class HpackDecoder
                             break;
                             
                         case ":status":
-                            Integer code = Integer.getInteger(value);
+                            Integer code = Integer.valueOf(value);
                             field = new StaticValueHttpField(header,name,value,code);
                             break;
                             
@@ -153,6 +166,9 @@ public class HpackDecoder
                             break;
                     }
                     
+                    if (LOG.isDebugEnabled())
+                        LOG.debug("decoded '"+field+"' by Lit"+(name_index>0?"IdxName":(huffmanName?"HuffName":"LitName"))+(huffmanValue?"HuffVal":"LitVal")+(indexed?"Idx":""));
+                    
                     // emit the field
                     _builder.emit(field);
                     
@@ -170,11 +186,14 @@ public class HpackDecoder
                 {
                     // change table size
                     int size = NBitInteger.decode(buffer,4);
+                    if (LOG.isDebugEnabled())
+                        LOG.debug("decode resize="+size);
                     _context.resize(size);
                 }
                 else if (f==3)
                 {
                     // clear reference set
+                    LOG.debug("decode clear");
                     _context.clearReferenceSet();
                 }   
             }

jetty-http2/http2-hpack/src/main/java/org/eclipse/jetty/http2/hpack/HpackEncoder.java

@@ -29,9 +29,13 @@ import org.eclipse.jetty.http2.hpack.HpackContext.Entry;
 import org.eclipse.jetty.io.ByteBufferPool.Lease;
 import org.eclipse.jetty.util.BufferUtil;
 import org.eclipse.jetty.util.TypeUtil;
+import org.eclipse.jetty.util.log.Log;
+import org.eclipse.jetty.util.log.Logger;
 
 public class HpackEncoder
 {   
+    public static final Logger LOG = Log.getLogger(HpackEncoder.class);
+    
     private final static HttpField[] __status= new HttpField[599];
     
     private final static EnumSet<HttpHeader> __NEVER_INDEX = 
@@ -100,7 +104,6 @@ public class HpackEncoder
 
     public void encodeMaxHeaderTableSize(ByteBuffer buffer, int maxHeaderTableSize)
     {
-        // TODO
         _context.resize(maxHeaderTableSize);
     }
 
@@ -143,34 +146,29 @@ public class HpackEncoder
 
         _context.removedUnusedReferences(buffer);
     }
-    
+
     private void encode(ByteBuffer buffer, HttpField field)
     {
-        
+        final int p=LOG.isDebugEnabled()?buffer.position():-1;
-        /*   
+        String encoding=null;
-        System.err.println("encode "+field);
+
-        int p=buffer.position();
-        try{
-        */
-        
         // TODO currently we do not check if there is enough space, so we will always
         // return true or fail nastily.
-        
+
         // Is there an entry for the field?
         Entry entry = _context.get(field);
-        
+
         if (entry!=null)
         {
             // if entry is already in the reference set, then nothing more to do.
             if (entry.isInReferenceSet())
             {
                 entry.used();
-                // System.err.println("In Reference Set");
+                encoding="InRefSet";
-                return;
             }
-            
+
             // Is this as static field
-            if (entry.isStatic())
+            else if (entry.isStatic())
             {
                 // TODO Strategy decision to make!
                 // Should we add to reference set or just always send as indexed?
@@ -179,130 +177,130 @@ public class HpackEncoder
                 // lets send as literal header, indexed name.
                 // We don't need never indexed because the cookie fields are name only and we can
                 // huffman encode the value for the same reason. 
-                               
+
                 // Add the token
                 buffer.put((byte)0x00);
                 // Add the name index
                 NBitInteger.encode(buffer,4,_context.index(entry));
                 // Add the value
                 buffer.put(entry.getStaticHuffmanValue());
-                
+
-                // System.err.println("Literal without Indexing, indexed name");
+                encoding="LiteralStaticIdxNameHuffmanValue";
-                return;
             }
-
+            else
-            // System.err.println("Indexed from Header Set");
-            
-            // So we can add the entry to the reference Set and emit the index;
-            _context.addToRefSet(entry);
-            int index=_context.index(entry);
-            
-            // TODO pregenerate indexes?
-            buffer.put((byte)0x80);
-            NBitInteger.encode(buffer,7,index);
-            return;
-        }
-        
-
-        // Must be a new entry, so we will have to send literally.
-        // TODO Strategy decision to make!
-        // What fields will we put in the reference set and what fields will we huffman encode?
-                
-        // Let's make these decisions by lookup of known fields
-        HttpHeader header = field.getHeader();
-        final boolean never_index;
-        final boolean huffman;
-        final boolean reference;
-        final int name_bits;
-        final byte mask;
-        if (header==null)
-        {
-            never_index=false;
-            huffman=true;
-            reference=true;
-            name_bits = 6;
-            mask=(byte)0x40;
-        }
-        else if (__USE_REFERENCE_SET.contains(header))
-        {
-            reference=true;
-            never_index=false;
-            huffman=!__DO_NOT_HUFFMAN.contains(header);
-            name_bits = 6;
-            mask=(byte)0x40;
-        }
-        else
-        {
-            reference=false;
-            never_index=__NEVER_INDEX.contains(header);
-            huffman=!__DO_NOT_HUFFMAN.contains(header);
-            name_bits = 4;
-            mask=never_index?(byte)0x01:(byte)0x00;
-        }
-        
-        // Add the mask bits
-        buffer.put(mask);
-        
-        // Look for a name Index
-        Entry name_entry = _context.get(field.getName());
-
-        // System.err.printf("Literal huff=%b refed=%b neverIdx=%b nameIdx=%b b=%d m=0x%02x%n",huffman,reference,never_index,name_entry!=null,name_bits,mask);
-        
-        if (name_entry!=null)
-            NBitInteger.encode(buffer,name_bits,_context.index(name_entry));
-        else
-        {
-            // Encode the name always with huffman
-            buffer.put((byte)0x80);
-            NBitInteger.encode(buffer,7,Huffman.octetsNeeded(field.getName()));
-            Huffman.encode(buffer,field.getName());
-        }
-        
-        // Add the literal value
-        String value=field.getValue();
-        if (huffman)
-        {
-            // huffman literal value
-            buffer.put((byte)0x80);
-            NBitInteger.encode(buffer,7,Huffman.octetsNeeded(value));
-            Huffman.encode(buffer,field.getValue());
-        }
-        else
-        {
-            // add literal assuming iso_8859_1
-            buffer.put((byte)0x00);
-            NBitInteger.encode(buffer,7,value.length());
-            for (int i=0;i<value.length();i++)
             {
-                char c=value.charAt(i);
+                encoding="IdxField";
-                if (c<' '|| c>127)
+
-                   throw new IllegalArgumentException();
+                // So we can add the entry to the reference Set and emit the index;
-                buffer.put((byte)c);
+                _context.addToRefSet(entry);
+                int index=_context.index(entry);
+
+                // TODO pregenerate indexes?
+                buffer.put((byte)0x80);
+                NBitInteger.encode(buffer,7,index);
             }
         }
-        
+        else
-        // If we want the field referenced, then we add it to our
-        // table and reference set.
-        if (reference)
         {
-            Entry new_entry=_context.add(field);
+            // Must be a new entry, so we will have to send literally.
-            if (new_entry!=null)
+            // TODO Strategy decision to make!
-                _context.addToRefSet(new_entry);
+            // What fields will we put in the reference set and what fields will we huffman encode?
+
+            // Let's make these decisions by lookup of known fields
+            HttpHeader header = field.getHeader();
+            final boolean never_index;
+            final boolean huffman;
+            final boolean reference;
+            final int name_bits;
+            final byte mask;
+            if (header==null)
+            {
+                never_index=false;
+                huffman=true;
+                reference=true;
+                name_bits = 6;
+                mask=(byte)0x40;
+            }
+            else if (__USE_REFERENCE_SET.contains(header))
+            {
+                reference=true;
+                never_index=false;
+                huffman=!__DO_NOT_HUFFMAN.contains(header);
+                name_bits = 6;
+                mask=(byte)0x40;
+            }
+            else
+            {
+                reference=false;
+                never_index=__NEVER_INDEX.contains(header);
+                huffman=!__DO_NOT_HUFFMAN.contains(header);
+                name_bits = 4;
+                mask=never_index?(byte)0x01:(byte)0x00;
+            }
+
+            // Add the mask bits
+            buffer.put(mask);
+
+            // Look for a name Index
+            Entry name_entry = _context.get(field.getName());
+
+            if (p>=0)
+            {
+                encoding="Literal"+
+                        ((name_entry==null)?"IdxName":"HuffName")+
+                        (huffman?"HuffName":"LitName")+
+                        (reference?"Idx":(never_index?"NeverIdx":""));
+            }
+            
+            if (name_entry!=null)
+                NBitInteger.encode(buffer,name_bits,_context.index(name_entry));
+            else
+            {
+                // Encode the name always with huffman
+                buffer.put((byte)0x80);
+                NBitInteger.encode(buffer,7,Huffman.octetsNeeded(field.getName()));
+                Huffman.encode(buffer,field.getName());
+            }
+
+            // Add the literal value
+            String value=field.getValue();
+            if (huffman)
+            {
+                // huffman literal value
+                buffer.put((byte)0x80);
+                NBitInteger.encode(buffer,7,Huffman.octetsNeeded(value));
+                Huffman.encode(buffer,field.getValue());
+            }
+            else
+            {
+                // add literal assuming iso_8859_1
+                buffer.put((byte)0x00);
+                NBitInteger.encode(buffer,7,value.length());
+                for (int i=0;i<value.length();i++)
+                {
+                    char c=value.charAt(i);
+                    if (c<' '|| c>127)
+                        throw new IllegalArgumentException();
+                    buffer.put((byte)c);
+                }
+            }
+
+            // If we want the field referenced, then we add it to our
+            // table and reference set.
+            if (reference)
+            {
+                Entry new_entry=_context.add(field);
+                if (new_entry!=null)
+                    _context.addToRefSet(new_entry);
+            }
+
+
         }
-        
+
-        return;
+        if (p>=0)
-        
-        /*
-        }
-        finally
         {
             int e=buffer.position();
-            System.err.println("'"+TypeUtil.toHexString(buffer.array(),buffer.arrayOffset()+p,e-p)+"'");
+            LOG.debug("encoded '{}' by {} to '{}'",field,encoding,TypeUtil.toHexString(buffer.array(),buffer.arrayOffset()+p,e-p));
         }
-        */
     }
-
-    
-    
-    
 }

jetty-http2/http2-hpack/src/main/java/org/eclipse/jetty/http2/hpack/StaticValueHttpField.java

@@ -30,12 +30,16 @@ public class StaticValueHttpField extends HttpField
     public StaticValueHttpField(HttpHeader header,String name, String valueString, Object value)
     {
         super(header,name,valueString);
+        if (value==null)
+            throw new IllegalArgumentException();
         _value=value;
     }
     
     public StaticValueHttpField(String name, String valueString, Object value)
     {
         super(name,valueString);
+        if (value==null)
+            throw new IllegalArgumentException();
         _value=value;
     }
 

jetty-http2/http2-server/src/test/java/org/eclipse/jetty/http2/server/HTTP2ServerTest.java

@@ -25,6 +25,7 @@ import java.nio.channels.SocketChannel;
 import java.util.concurrent.CountDownLatch;
 import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicReference;
+
 import javax.servlet.ServletException;
 import javax.servlet.http.HttpServlet;
 import javax.servlet.http.HttpServletRequest;
@@ -35,6 +36,9 @@ import org.eclipse.jetty.http.HttpMethod;
 import org.eclipse.jetty.http.HttpScheme;
 import org.eclipse.jetty.http2.frames.HeadersFrame;
 import org.eclipse.jetty.http2.generator.Generator;
+import org.eclipse.jetty.http2.hpack.HpackContext;
+import org.eclipse.jetty.http2.hpack.HpackDecoder;
+import org.eclipse.jetty.http2.hpack.HpackEncoder;
 import org.eclipse.jetty.http2.hpack.MetaData;
 import org.eclipse.jetty.http2.parser.Parser;
 import org.eclipse.jetty.io.ByteBufferPool;
@@ -71,6 +75,9 @@ public class HTTP2ServerTest
         generator = new Generator(byteBufferPool);
 
         server.start();
+        HpackContext.LOG.setDebugEnabled(true);
+        HpackEncoder.LOG.setDebugEnabled(true);
+        HpackDecoder.LOG.setDebugEnabled(true);
     }
 
     @After