11

I thought I understood how maps are supposed to work. So, I thought I would try to be clever and use a custom class as the key in a map in Apex. The results, however have been unexpected.

It's so fundamental that I must be missing something stupid, but I can't see it yet. In the actual application, the custom class I'm using as a key is a bit like an XPath specifier, identifying an object in a tree by the path to that object.

Below, I've distilled it right down to something you can run as anonymous Apex, and still get results that baffle me:

Integer nCallsToEquals = 0;

public class HashingTest {
    private String s;

    public HashingTest(HashingTest ht) {
        this.s = ht.s;
    }

    public HashingTest(String s) {
        this.s = s;
    }

    public Integer hashCode() {
        return s.hashCode();
    }

    public Boolean equals(Object o) {
        ++nCallsToEquals;
        if(o instanceof HashingTest) {
            return s == ((HashingTest)o).s;
        } else {
            return false;
        }
    }

}

HashingTest k1 = new HashingTest('a');
HashingTest k2 = new HashingTest('b');

System.debug('k1.hashCode(): ' + k1.hashCode());
System.debug('k2.hashCode(): ' + k2.hashCode());

Map<HashingTest, Integer> aMap = new Map<HashingTest, Integer>();

aMap.put(k1, 1);
aMap.put(k2, 2);

nCallsToEquals = 0;
aMap.get(k1);
System.debug('nCallsToEquals: ' + nCallsToEquals);
System.assertEquals(1, nCallsToEquals);
nCallsToEquals = 0;
aMap.get(k2);
System.debug('nCallsToEquals: ' + nCallsToEquals);
System.assertEquals(1, nCallsToEquals);

System.debug('aMap: ' + aMap);
System.debug('calling keySet()');
aMap.keySet();
System.debug('aMap: ' + aMap);

nCallsToEquals = 0;
aMap.get(k1);
System.debug('nCallsToEquals: ' + nCallsToEquals);
System.assertEquals(1, nCallsToEquals);
nCallsToEquals = 0;
aMap.get(k2);
System.debug('nCallsToEquals: ' + nCallsToEquals);
System.assertEquals(1, nCallsToEquals);

In my code, HashingTest is suitable for use as a key because it specifies implementations for hashCode() and equals() (they just delegate to String).

And I have a counter to see how many times equals() gets called. This allows us to count the number of collisions in the hashmap implementation.

After populating the map, I output the hashcodes for the keys to make sure they are different (they are).

Then, I get the values back out of the map using the keys. I reset the counter before each get(), so that I can see how many times equals() is called.

The first time, equals() is called once for getting k1 and once for k2. Then, after I call keyset(), it is called once for k1 and twice for k2. As if k1 and k2 are now in the same bucket in the hashmap.

This seems like a triviality, but the numbers explode very quickly. I came to this because I have map with 185 entries where I need to access key-value pairs. I was iterating over the keyset and calling get() on each key. Due to this behaviour, it takes 1 + 2 + 3 + ... + 185 = 17,020 calls to equals() to achieve this.

Here's the debug output in its entirety:

15:48:47.1 (3318843)|USER_DEBUG|[32]|DEBUG|k1.hashCode(): 97
15:48:47.1 (3513197)|USER_DEBUG|[33]|DEBUG|k2.hashCode(): 98
15:48:47.1 (4144662)|USER_DEBUG|[42]|DEBUG|nCallsToEquals: 1
15:48:47.1 (4386196)|USER_DEBUG|[45]|DEBUG|nCallsToEquals: 1
15:48:47.1 (4749309)|USER_DEBUG|[47]|DEBUG|aMap: {HashingTest:[s=a]=1, HashingTest:[s=b]=2}
15:48:47.1 (4792183)|USER_DEBUG|[48]|DEBUG|calling keySet()
15:48:47.1 (5045209)|USER_DEBUG|[50]|DEBUG|aMap: {HashingTest:[s=a]=1, HashingTest:[s=b]=2}
15:48:47.1 (5180286)|USER_DEBUG|[54]|DEBUG|nCallsToEquals: 1
15:48:47.1 (5333300)|USER_DEBUG|[57]|DEBUG|nCallsToEquals: 2

A couple of updates:

  1. I tried using System.hashCode(s) instead of s.hashCode() but it made no difference
  2. This problem certainly looks related to hashCode() is never called when adding to Maps and Sets (as @keith-c answered below), but I don't believe it is entirely down to the same Known Issue (https://success.salesforce.com/issues_view?id=a1p30000000eMoeAAE). I've rerun the code with all logging flags set to NONE, and put in assertions to check the value of nCallsToEquals. It then fails on the final assertion (getting k2 after calling keySet()) and generates no debug log at all. If I set the logging flags to FINEST, then it fails on the second assertion (the first time we get k2, before calling keySet()), which is what I would expect after reading the Known Issue. To me, this looks like there ought to be a separate bug filed with SF for a call to keySet() changing the underlying representation of a map.
  • (I believe this is somehow related to order of iteration being predictable) – kurunve Jan 4 '18 at 16:00
  • I don't see how iteration order has anything to do with this? – Aidan Jan 4 '18 at 16:11
  • 1
    This looks like a bug. nCallsToEquals should equal 0 the entire time. I'll ask around. – sfdcfox Jan 4 '18 at 16:58
  • I would have expected 1 call to equals each time? Even if there's one entry in the bucket, then you still need to make sure it's not a hash collision? I did find this other question and known issue which might explain it: salesforce.stackexchange.com/questions/46525/… In that question, they say there are two representations of map one of which does a full traversal – Aidan Jan 4 '18 at 17:01
  • 1
    @RobertSösemann I should have mentioned that in the question: I tried it but it made no difference – Aidan Jan 4 '18 at 22:16
6

Aidan has already linked to the post that describes what I think is the likely cause: hashCode() is never called when adding to Maps and Sets.

Running with the debug level turned down would confirm.

A key point from that:

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.)

with the supporting comment:

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

I guess the view is that reasonable performance is not an explicit part of the contract...

| improve this answer | |
  • 17k string comparisons shouldn't be a huge performance hit. Granted it won't be as fast as 2 (or 200 or whatever) – Adrian Larson Jan 4 '18 at 17:36
  • 1
    @AdrianLarson But we use maps with the intention of avoiding exponential cost growth. If a map with 1,000 entries is accessed inside a 1,000 item loop that's an exponentially growing cost of 1,000,000 not the linearly growing cost of 1,000 you would expect. – Keith C Jan 4 '18 at 17:40
  • I wasn't running it with lots of debug enabled. I noticed that it did start calling equals() on every element when I switched it to FINEST, even the first time around. But, I don't think it's related to debug levels in the original scenario. Will have a bit more of a play because I think it's the same circumstance as the linked question, but with slight different conditions causing it. – Aidan Jan 4 '18 at 22:18
  • 1
    Right, I've run some more tests playing with debug levels and it doesn't appear that debug levels are causing the problem (details in edit to the question). So, I don't think that the existing question fully explains this. @AdrianLarson I came to this via a CPU timeout, and seeing it take about 2s to iterate over my map of 185 values so it is definitely a problem in my real code. I've abstracted it out for the question, but hashCode() and equals() are a bit more expensive in the real code. – Aidan Jan 5 '18 at 9:49
  • @Aidan Interesting. Thanks for sharing your results here. Information on these internal quirks is hard to come by and your investigations may well help others in the future. – Keith C Jan 5 '18 at 10:22

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.