hashCode() is never called when adding to Maps and Sets

Question

Given the following Apex class, which implements equals() and hashCode() as per the Using Custom Types in Map Keys and Sets documentation:

public class Foo
{
    private Integer x;
    
    public Foo(Integer x)
    {
        this.x = x;
    }
    
    public Boolean equals(Object obj) 
    {
        System.debug('equals');
        
        if(obj instanceof Foo)
        {
            Foo f = (Foo)obj;
            return x == f.x;
        }
        
        return false;
    }

    public Integer hashCode() 
    {
        System.debug('hashCode');
        return x;
    }
}

When running the following in the Execute Anonymous window:

Foo f1 = new Foo(1);
Foo f2 = new Foo(2);

System.debug('Map');

Map<Foo, Boolean> m = new Map<Foo, Boolean>();

System.debug('put');
m.put(f1, true);
m.put(f2, true);

System.debug('get');
System.debug(m.get(f1));
System.debug(m.get(f2));

System.debug('Set');

Set<Foo> s = new Set<Foo>();

System.debug('add');
s.add(f1);
s.add(f2);

System.debug('contains');
System.debug(s.contains(f1));
System.debug(s.contains(f2));

I get the following output in the log:

10:20:47.109 (109419811)    USER_DEBUG  [4]|DEBUG|Map
10:20:47.113 (113647288)    USER_DEBUG  [8]|DEBUG|put
10:20:47.197 (197941404)    USER_DEBUG  [12]|DEBUG|equals
10:20:47.202 (202365558)    USER_DEBUG  [12]|DEBUG|get
10:20:47.220 (220325097)    USER_DEBUG  [12]|DEBUG|equals
10:20:47.245 (245972058)    USER_DEBUG  [12]|DEBUG|equals
10:20:47.250 (250500074)    USER_DEBUG  [13]|DEBUG  TRUE
10:20:47.267 (267329766)    USER_DEBUG  [12]|DEBUG|equals
10:20:47.271 (271834178)    USER_DEBUG  [14]|DEBUG|true
10:20:47.271 (271888873)    USER_DEBUG  [16]|DEBUG|Set
10:20:47.275 (275988792)    USER_DEBUG  [20]|DEBUG|add
10:20:47.296 (296012585)    USER_DEBUG  [12]|DEBUG|equals
10:20:47.301 (301160512)    USER_DEBUG  [24]|DEBUG|contains
10:20:47.324 (324164712)    USER_DEBUG  [12]|DEBUG|equals
10:20:47.351 (351133028)    USER_DEBUG  [12]|DEBUG|equals
10:20:47.357 (357265136)    USER_DEBUG  [25]|DEBUG|true
10:20:47.382 (382010122)    USER_DEBUG  [12]|DEBUG|equals
10:20:47.388 (388259431)    USER_DEBUG  [26]|DEBUG|true

As you can see, hashCode() is not called once, instead equals() is called against all existing members of the collection (ok, that's maybe not clear from the log, but increase the volumes and it's very clear, it's also take forever when the Map gets above about 10 elements) which goes contrary to this pair of statements in the Map documentation as well as the standard Java implementation.

• Unlike Java, Apex developers do not need to reference the algorithm that is used to implement a map in their declarations (for example, HashMap or TreeMap). Apex uses a hash structure for all maps.

• Uniqueness of map keys of user-defined types is determined by the equals and hashCode methods, which you provide in your classes. Uniqueness of keys of all other non-primitive types, such as sObject keys, is determined by comparing the objects’ field values.

I'm sure my implementation of hashCode() is 'right' (other than being a terrible means of creating a hash) since the following produces the correct output:

Object o = new Foo(1);
System.debug(o.hashCode());
System.debug(System.hashCode(o));

Log output:

10:41:11.659 (659323616)    USER_DEBUG  [25]|DEBUG|hashCode
10:41:11.659 (659395719)    USER_DEBUG  [2]|DEBUG|1
10:41:11.745 (745368812)    USER_DEBUG  [25]|DEBUG|hashCode
10:41:11.745 (745439365)    USER_DEBUG  [3]|DEBUG|1

I am seeing this issue across multiple Orgs on multiple instances. Is this a bug with the platform? Has this worked correctly in previous releases?

Answer 1

It took 2 months, but this is the "final" answer we got from Support on this topic. Note that the investigation by Tier 3 resulted in this Known Issue being filed which was ultimately the cause for our documented behavior (i.e. by setting a log filter override on a class with a hashCode()/equals() implementation, it effectively disabled hashCode() from being called)

Here's the Known Issue:

https://success.salesforce.com/issues_view?id=a1p30000000eMoeAAE

And here's the explanation on why FINEST vs. DEBUG makes a difference

Here is a recap of the current issue:

with log level = debug

DEBUG|Final HashableClass.hashCodeCount=10 DEBUG|Final HashableClass.equalsCount=0

with log level = finest

DEBUG|Final HashableClass.hashCodeCount=0 DEBUG|Final HashableClass.equalsCount=45

In this testcase, adding 10 HashableClass objects to a Set causes 10 hasCode() method calls because there are not any hash conflicts.

However, if the log level is set to FINEST, a Set Interpreter Instance is converted to a Set Wrapper Instance in order to log an event of a static field's assignment at line#6 (hashables = new Set(); ) in the HashableClassDemo class.

When an object is added to a Set Wrapper Instance, we traverse the entire list in it and compare objects for equality. That's why the number of the equals() calls becomes 45 (1 + 2 + 3 + 4 + 5 + 6 + 7 + 8 + 9).

========================

The difference comes from underlying Map representations.

Internally, we have 2 representations for Map.

1) One keeps the objects in a Map in the interpreter (apex) native representation.And in this case, if the put() method is called to it, uniqueness of keys are determined by using both of hashCode() and equals(). (A value returned by the hashCode() method is used to determine a bucket, and the equals() method is used to identify objects in the same bucket.)

2) Once a Map is marshaled, the other representation is used.In this representation, in the put() method call, we traverse all objects in a Map and linearly check uniqueness of keys using the equals() method if a user defined key is used.That's why you don't see the hashCode() method calls but see the equals() method calls in your testcase. (In your org, the Map object is marshaled when trying to generate a debug message for local variable assignments.)

However, the latter representation does not violate the Map contract. Any method call defined in the Map class works as per doc.

This is the repro case that goes along with the investigation above:

public with sharing class HashableClass {
    public static Integer hashCodeCount = 0;
    public static Integer equalsCount = 0;

    private Integer simpleMember;

    public HashableClass(Integer val) {
        this.simpleMember = val;
    }

    public Integer hashCode(){
        hashCodeCount++;
        System.debug('entering HashableClass.hashCode hashCodeCount=' + hashCodeCount);
        return simpleMember;
    }

    public Boolean equals(Object other){
        equalsCount++;
        System.debug('entering HashableClass.equals equalsCount=' + equalsCount);
        if(other == null){
            return false;
        }
        if(!(other instanceof HashableClass)){
            return false;
        }
        return ((HashableClass)other).simpleMember == this.simpleMember;
    }
}

public with sharing class HashableClassDemo {
    private static Set<HashableClass> hashables;
    private static Set<HashableClass.InnerHashableClass> innerHashables;

    public static void demo() {
        hashables = new Set<HashableClass>();

        for(Integer i=0; i<10; i++){
            HashableClass h = new HashableClass(i);
            hashables.add(h);
        }

        System.debug('Final HashableClass.hashCodeCount=' + HashableClass.hashCodeCount);
        System.debug('Final HashableClass.equalsCount=' + HashableClass.equalsCount);
    }
}

Answer 2

Taking your code and wrapping it in a test with counters for the calls confirms hashCode is called because the test passes. I don't know why you are experiencing different results but suggest you move to test cases to check behaviour.

PS See comment thread - different results on different instances.

@isTest
private class HashCodeTest {
    public class Foo
    {
        Integer equalsCalls = 0;
        Integer hashCodeCalls = 0;

        private Integer x;

        public Foo(Integer x)
        {
            this.x = x;
        }

        public Boolean equals(Object obj) 
        {
            equalsCalls++;
            System.debug('equals');

            if(obj instanceof Foo)
            {
                Foo f = (Foo)obj;
                return x == f.x;
            }

            return false;
        }

        public Integer hashCode() 
        {
            hashCodeCalls++;
            System.debug('hashCode');
            return x;
        }
    }

    @isTest
    static void testMap() {

        Foo f1 = new Foo(1);
        Foo f2 = new Foo(2);

        Map<Foo, Boolean> m = new Map<Foo, Boolean>();
        m.put(f1, true);
        m.put(f2, false);
        System.assert(f1.hashCodeCalls > 0);
        System.assert(f2.hashCodeCalls > 0);
    }

    @isTest
    static void testSet() {

        Foo f1 = new Foo(1);
        Foo f2 = new Foo(2);

        Set<Foo> s = new Set<Foo>();
        s.add(f1);
        s.add(f2);
        System.assert(f1.hashCodeCalls > 0);
        System.assert(f2.hashCodeCalls > 0);
    }
}