Failure running MachOImageReader.Self_DyldImages

[Scott Graham]

This isn't happening on the waterfall, but I get this in both Debug and Release locally.

I don't fully understand the error. I guess I have something installed that exercises the "not currently seen in the wild" path near snapshot/mac/mach_o_image_reader_test.cc:406 ?

scottmg:~/work/crashpad/crashpad ((2289339...))]$ ninja -C out/Debug

ninja: Entering directory `out/Debug'

[0->72/72 ~0] STAMP obj/All.actions_depends.stamp

[scottmg:~/work/crashpad/crashpad ((2289339...))]$ out/Debug/snapshot_test --gtest_filter=MachOImageReader.Self_DyldImages

Running main() from gtest_main.cc

Note: Google Test filter = MachOImageReader.Self_DyldImages

[==========] Running 1 test from 1 test case.

[----------] Global test environment set-up.

[----------] 1 test from MachOImageReader

[ RUN      ] MachOImageReader.Self_DyldImages

[94327:21853544:20150203,220553.742658:WARNING mach_o_image_symbol_table_reader.cc:165] non-external symbol in extdefsym, symbol index 59, module /System/Library/PrivateFrameworks/Heimdal.framework/Versions/A/Heimdal, address 0x108085000

../../snapshot/mac/mach_o_image_reader_test.cc:406: Failure

Value of: actual_image->LookUpExternalDefinedSymbol(name, &actual_address)

  Actual: false

Expected: true

Google Test trace:

../../snapshot/mac/mach_o_image_reader_test.cc:392: _TicketFlags2int

../../snapshot/mac/mach_o_image_reader_test.cc:543: index 103, image /System/Library/PrivateFrameworks/Heimdal.framework/Versions/A/Heimdal

../../snapshot/mac/mach_o_image_reader_test.cc:487: Failure

Expected: ExpectSymbol(entry, name, actual_image) doesn't generate new fatal failures in the current thread.

  Actual: it does.

Google Test trace:

../../snapshot/mac/mach_o_image_reader_test.cc:543: index 103, image /System/Library/PrivateFrameworks/Heimdal.framework/Versions/A/Heimdal

../../snapshot/mac/mach_o_image_reader_test.cc:568: Failure

Expected: ExpectSymbolTable(mach_header, &image_reader) doesn't generate new fatal failures in the current thread.

  Actual: it does.

Google Test trace:

../../snapshot/mac/mach_o_image_reader_test.cc:543: index 103, image /System/Library/PrivateFrameworks/Heimdal.framework/Versions/A/Heimdal

[  FAILED  ] MachOImageReader.Self_DyldImages (1704 ms)

[----------] 1 test from MachOImageReader (1704 ms total)

[Mark Mentovai]

What OS version are you using? I’ll probably want to see the actual file you have for that module.

--
You received this message because you are subscribed to the Google Groups "Crashpad-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to crashpad-dev...@chromium.org.
To post to this group, send email to crashp...@chromium.org.
To view this discussion on the web visit https://groups.google.com/a/chromium.org/d/msgid/crashpad-dev/CANHK6Rba0Dio1FceKcC8wZxh51svi5qbQMY4DAqt54SKq%2B08iA%40mail.gmail.com.

[Scott Graham]

Running on 10.9.5.

File at: https://dl.dropboxusercontent.com/u/116514/Heimdal

[Mark Mentovai]

I’m on 10.9.5 too. I’ve got the same file as you (SHA-1 922462a1638073b9a5f74a1bde2cf9800fc3b7e2) and I’ve verified that it’s loaded and examined when I run snapshot_test too. Something weird is happening after the module’s loaded, and what I’m seeing doesn’t match what you’re seeing.

For this problem symbol at index 59 (per the snippet above), what do you see for the various fields in symbol, and for the symbol name? I’m attaching a patch that will dump this information for this module.

Is it always the same symbol and set of data? For me, index 59 is (with the patch)

59 0xf 0xa 0x0 0x7fff721cd8f0 0x2015e90 _asn1_oid_id_pkcs7_data

which looks totally normal. (Slight variations are expected in value column due to ASLR, it’s enough for it to end in 0x8f0.)

Is this a new occurrence for you?

[Scott Graham]

It's started relatively recently, and I don't think it's related to changes in the crashpad code base. It could correspond with installing something on the system, though I can't think of anything off the top of my head.

Log with patch below. (should I reorder to get more info on 59?)

[scottmg:~/work/crashpad/crashpad ((2289339...))]$ git apply ~/Downloads/heimdal_test.patch

[scottmg:~/work/crashpad/crashpad ((2289339...))]$ ninja -C out/Debug snapshot_test

ninja: Entering directory `out/Debug'

Recompacting deps...

[0->3/3 ~0] LINK snapshot_test, POSTBUILDS

[scottmg:~/work/crashpad/crashpad ((2289339...))]$ out/Debug/snapshot_test --gtest_filter=MachOImageReader.Self_DyldImages

Running main() from gtest_main.cc

Note: Google Test filter = MachOImageReader.Self_DyldImages

[==========] Running 1 test from 1 test case.

[----------] Global test environment set-up.

[----------] 1 test from MachOImageReader

[ RUN      ] MachOImageReader.Self_DyldImages

found Heimdal

[25366:22135294:20150204,142658.808032:INFO mach_o_image_symbol_table_reader.cc:114] symbol count 1185

0 0xf 0x1 0x0 0x3a438 0x4 _TicketFlags2int

1 0xf 0xd 0x10 0x73168 0x15 ___crashreporter_info__

2 0xf 0x1 0x0 0x3e8d0 0x2d __hx509_cert_private_key

3 0xf 0x1 0x0 0x3d90f 0x46 __hx509_cert_set_key

4 0xf 0x1 0x0 0x4795c 0x5b __hx509_certs_keys_free

5 0xf 0x1 0x0 0x478fc 0x73 __hx509_certs_keys_get

6 0xf 0x1 0x0 0x440af 0x8a __hx509_generate_private_key

7 0xf 0x1 0x0 0x44084 0xa7 __hx509_generate_private_key_bits

8 0xf 0x1 0x0 0x44090 0xc9 __hx509_generate_private_key_free

9 0xf 0x1 0x0 0x43fe8 0xeb __hx509_generate_private_key_init

10 0xf 0x1 0x0 0x44075 0x10d __hx509_generate_private_key_is_ca

11 0xf 0x1 0x0 0x469f0 0x130 __hx509_map_file_os

12 0xf 0x1 0x0 0x44256 0x144 __hx509_private_key_ref

13 0xf 0x1 0x0 0x4d965 0x15c __hx509_request_add_dns_name

14 0xf 0x1 0x0 0x4d9af 0x179 __hx509_request_add_email

15 0xf 0x1 0x0 0x4dc7a 0x193 __hx509_request_parse

16 0xf 0x1 0x0 0x4de10 0x1a9 __hx509_request_print

17 0xf 0x1 0x0 0x4d9f9 0x1bf __hx509_request_to_pkcs10

18 0xf 0x1 0x0 0x46a1f 0x1d9 __hx509_unmap_file_os

19 0xf 0x1 0x0 0x46a2d 0x1ef __hx509_write_file

20 0xf 0xb 0x0 0x6fd40 0x202 __krb5_AES_string_to_default_iterator

21 0xf 0x1 0x0 0x3e9d 0x228 __krb5_build_authenticator

22 0xf 0x1 0x0 0x9776 0x243 __krb5_crc_init_table

23 0xf 0x1 0x0 0x97c3 0x259 __krb5_crc_update

24 0xf 0x1 0x0 0x2567a 0x26b __krb5_dh_group_ok

25 0xf 0x1 0x0 0x47e7 0x27e __krb5_expand_default_cc_name

26 0xf 0x1 0x0 0x3665e 0x29c __krb5_fast_armor_key

27 0xf 0x1 0x0 0x129a4 0x2b2 __krb5_get_host_realm_int

28 0xf 0x1 0x0 0x2584b 0x2cc __krb5_get_init_creds_opt_set_pkinit_user_cert

29 0xf 0x1 0x0 0x364c2 0x2fb __krb5_get_int

30 0xf 0x1 0x0 0xf9bf 0x30a __krb5_get_krbtgt

31 0xf 0x1 0x0 0x1f5dc 0x31c __krb5_have_debug

32 0xf 0x1 0x0 0x1626e 0x32e __krb5_init_creds_get_cred_client

33 0xf 0x1 0x0 0x16264 0x350 __krb5_init_creds_get_cred_endtime

34 0xf 0x1 0x0 0x13f04 0x373 __krb5_init_creds_set_pku2u

35 0xf 0x1 0x0 0x9396 0x38f __krb5_init_etype

36 0xf 0x1 0x0 0x18b61 0x3a1 __krb5_kcm_get_initial_ticket

37 0xf 0x1 0x0 0x18c69 0x3bf __krb5_kcm_get_status

38 0xf 0x1 0x0 0x18c8d 0x3d5 __krb5_kcm_ntlm_challenge

39 0xf 0x1 0x0 0x22233 0x3ef __krb5_pac_sign

40 0xf 0x1 0x0 0x253c2 0x3ff __krb5_parse_moduli

41 0xf 0x1 0x0 0x25c6e 0x413 __krb5_pk_enterprise_cert

42 0xf 0x1 0x0 0x22d4f 0x42d __krb5_pk_find_cert

43 0xf 0x1 0x0 0x34e40 0x441 __krb5_pk_kdf

44 0xf 0x1 0x0 0x24ce2 0x44f __krb5_pk_load_id

45 0xf 0x1 0x0 0x25f2b 0x461 __krb5_pk_match_cert

46 0xf 0x1 0x0 0x23031 0x476 __krb5_pk_mk_ContentInfo

47 0xf 0x1 0x0 0x34c45 0x48f __krb5_pk_octetstring2key

48 0xf 0x1 0x0 0x26847 0x4a9 __krb5_plugin_find

49 0xf 0x1 0x0 0x26c5b 0x4bc __krb5_plugin_free

50 0xf 0x1 0x0 0x2673c 0x4cf __krb5_plugin_get_next

51 0xf 0x1 0x0 0x26733 0x4e6 __krb5_plugin_get_symbol

52 0xf 0x1 0x0 0x335d 0x4ff __krb5_principal2principalname

53 0xf 0x1 0x0 0x3370 0x51e __krb5_principalname2krb5_principal

54 0xf 0x1 0x0 0x364a7 0x542 __krb5_put_int

55 0xf 0x1 0x0 0x1fffa 0x551 __krb5_s4u2self_to_checksumdata

56 0xf 0x1 0x0 0x1ae0b 0x571 __krb5_state_srv_sort

57 0xf 0xb 0x0 0x6ffd8 0x587 _asn1_TicketFlags_table_units

58 0xb 0x0 0x0 0x5b7 0x5a5 _asn1_fuzzer_done

[25366:22135294:20150204,142658.808966:WARNING mach_o_image_symbol_table_reader.cc:194] non-external symbol in extdefsym, symbol index 59, module /System/Library/PrivateFrameworks/Heimdal.framework/Versions/A/Heimdal, address 0x10b316000

../../snapshot/mac/mach_o_image_reader_test.cc:406: Failure

Value of: actual_image->LookUpExternalDefinedSymbol(name, &actual_address)

  Actual: false

Expected: true

Google Test trace:

../../snapshot/mac/mach_o_image_reader_test.cc:392: _TicketFlags2int

../../snapshot/mac/mach_o_image_reader_test.cc:543: index 103, image /System/Library/PrivateFrameworks/Heimdal.framework/Versions/A/Heimdal

../../snapshot/mac/mach_o_image_reader_test.cc:487: Failure

Expected: ExpectSymbol(entry, name, actual_image) doesn't generate new fatal failures in the current thread.

  Actual: it does.

Google Test trace:

../../snapshot/mac/mach_o_image_reader_test.cc:543: index 103, image /System/Library/PrivateFrameworks/Heimdal.framework/Versions/A/Heimdal

../../snapshot/mac/mach_o_image_reader_test.cc:568: Failure

Expected: ExpectSymbolTable(mach_header, &image_reader) doesn't generate new fatal failures in the current thread.

  Actual: it does.

Google Test trace:

../../snapshot/mac/mach_o_image_reader_test.cc:543: index 103, image /System/Library/PrivateFrameworks/Heimdal.framework/Versions/A/Heimdal

[  FAILED  ] MachOImageReader.Self_DyldImages (606 ms)

[----------] 1 test from MachOImageReader (606 ms total)

[Mark Mentovai]

I guess 59 in the LOG is the same as 58 in the fprintf, as long as skip_count is 1.

At index 58, 0xb is an external (0x1) indirect (0xa) type. _asn1_fuzzer_done is an indirect symbol.

Here’s what I get in that area:

56 0xf 0x1 0x0 0x7fff8c2fee0b 0x2015e40 __krb5_state_srv_sort

57 0xf 0xb 0x0 0x7fff721d1fd8 0x2015e56 _asn1_TicketFlags_table_units

58 0xf 0xa 0x0 0x7fff721cef60 0x2015e74 _asn1_oid_id_dhpublicnumber

59 0xf 0xa 0x0 0x7fff721cd8f0 0x2015e90 _asn1_oid_id_pkcs7_data

60 0xf 0xa 0x0 0x7fff721cd910 0x2015ea8 _asn1_oid_id_pkcs7_envelopedData

61 0xf 0xa 0x0 0x7fff721cd900 0x2015ec9 _asn1_oid_id_pkcs7_signedData

62 0xf 0xa 0x0 0x7fff721ceee0 0x2015ee7 _asn1_oid_id_rsadsi_des_ede3_cbc

We’re kind of on the same page until index 58, but the other weird thing is that we have wildly different addresses and offsets. Mine look like the module was loaded out of the dyld shared cache, and yours look like it was loaded standalone. That’s weird.

Sure enough, when I set DYLD_SHARED_REGION=avoid, I get a similar test failure, although mine happens much sooner, while processing CoreFoundation. Again, it’s with a symbol showing type 0xb:

1227 0xb 0x0 0x0 0x8747 0x8730 _OBJC_CLASS_$_NSObject

[24446:449868:20150204,175122.463006:WARNING mach_o_image_symbol_table_reader.cc:194] non-external symbol in extdefsym, symbol index 7432, module /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation, address 0x102003000

When I run nm -p (-p is unsorted) on the image on disk (as opposed to in memory as loaded by dyld, which is what MachOImageReader does), I see these indirect symbols in the symbol table at the same indices that you do. I wasn’t expecting those there, but they’re both indirect and external, so OK, we’ll deal with them.

In other words: your initial suspicion was right, this is the “not currently seen in the wild” now showing up.

Does https://codereview.chromium.org/901463004/ work for you?

[Scott Graham]

Yes, all the tests pass with that CL, thanks!

(I don't understand the details though, so I will leave review for Robert.)

[Mark Mentovai]

Great! I’ll send it to him for review.