After upgrading opensc & co to version 0.15.0-1, the following no longer
works:

 $ pkcs11-tool -O
 pkcs11-tool: pkcs15-pubkey.c:1064: sc_pkcs15_dup_pubkey: Assertion `key
 && out' failed.
 zsh: abort      pkcs11-tool -O

Downgrading opensc-pkcs11 to 0.14.0-2 fixes the problem.

After rebuilding opensc with DEB_BUILD_OPTIONS="nostrip noopt", the
backtrace is:

(gdb) bt full
#0  0x00007ffff6dc4107 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
        resultvar = 0
        pid = 16092
        selftid = 16092
#1  0x00007ffff6dc54e8 in __GI_abort () at abort.c:89
        save_stage = 2
        act = {__sigaction_handler = {sa_handler = 0x7fffffffebda, sa_sigaction = 0x7fffffffebda}, sa_mask = {__val = {140737336246689, 140737344795595, 1064, 4,
              140737488344800, 4294957152, 1, 140733193388032, 0, 0, 0, 21474836480, 140737336246215, 140737488344952, 140737354092544, 140737336261864}},
          sa_flags = -143558062, sa_restorer = 0x7ffff77181e0 <__PRETTY_FUNCTION__.12239>}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00007ffff6dbd226 in __assert_fail_base (fmt=0x7ffff6ef3ce8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n",
    assertion=assertion@entry=0x7ffff7717a52 "key && out", file=file@entry=0x7ffff77173cb "pkcs15-pubkey.c", line=line@entry=1064,
    function=function@entry=0x7ffff77181e0 <__PRETTY_FUNCTION__.12239> "sc_pkcs15_dup_pubkey") at assert.c:92
        str = 0x650590 ""
        total = 4096
#3  0x00007ffff6dbd2d2 in __GI___assert_fail (assertion=0x7ffff7717a52 "key && out", file=0x7ffff77173cb "pkcs15-pubkey.c", line=1064,
    function=0x7ffff77181e0 <__PRETTY_FUNCTION__.12239> "sc_pkcs15_dup_pubkey") at assert.c:101
No locals.
#4  0x00007ffff75a805e in sc_pkcs15_dup_pubkey (ctx=0x61e160, key=0x0, out=0x63da10) at pkcs15-pubkey.c:1064
        pubkey = 0x0
        rv = 0
        alg = 0x7fffffffd880 "\320\330\377\377\377\177"
        alglen = 140737343233935
        __PRETTY_FUNCTION__ = "sc_pkcs15_dup_pubkey"
        __FUNCTION__ = "sc_pkcs15_dup_pubkey"
#5  0x00007ffff6952271 in __pkcs15_prkey_bind_related (fw_data=0x633ef0, pk=0x63d9c0) at framework-pkcs15.c:770
        pubkey = 0x63dd80
        obj = 0x63dd80
        id = 0x63b1a0
        i = 7
        __FUNCTION__ = "__pkcs15_prkey_bind_related"
#6  0x00007ffff6952600 in pkcs15_bind_related_objects (fw_data=0x633ef0) at framework-pkcs15.c:838
        obj = 0x63d9c0
        i = 1
        __FUNCTION__ = "pkcs15_bind_related_objects"
#7  0x00007ffff6952f20 in _pkcs15_create_typed_objects (fw_data=0x633ef0) at framework-pkcs15.c:1062
        rv = 0
        __FUNCTION__ = "_pkcs15_create_typed_objects"
#8  0x00007ffff6953c71 in pkcs15_create_tokens (p11card=0x6335a0, app_info=0x0, first_slot=0x7fffffffdbf8) at framework-pkcs15.c:1276
        fw_data = 0x633ef0
        ffda = 0x0
        auth_user_pin = 0x63b4a0
        auth_sign_pin = 0x0
        fauo = 0x0
        slot = 0x0
        i = 0
        rv = 0
        idx = 0
        __FUNCTION__ = "pkcs15_create_tokens"
#9  0x00007ffff694bb7b in card_detect (reader=0x6331a0) at slot.c:292
        atrblock = 0x0
        enable_InitToken = 0
        app_generic = 0x0
        first_slot = 0x0
        p11card = 0x6335a0
        rc = 0
        rv = 0
        i = 0
        j = 32767
        __FUNCTION__ = "card_detect"
#10 0x00007ffff694b207 in initialize_reader (reader=0x6331a0) at slot.c:144
        i = 1
        rv = 0
        conf_block = 0x62df10
        list = 0x0
        __FUNCTION__ = "initialize_reader"
#11 0x00007ffff6945298 in C_Initialize (pInitArgs=0x0) at pkcs11-global.c:254
        rv = 0
        current_pid = 16092
        rc = 0
        i = 0
        ctx_opts = {ver = 0, app_name = 0x7ffff696383e "opensc-pkcs11", flags = 0, thread_ctx = 0x7ffff6b6f560 <sc_thread_ctx>}
        __FUNCTION__ = "C_Initialize"
#12 0x000000000040304e in ?? ()
No symbol table info available.
#13 0x00007ffff6db0b45 in __libc_start_main (main=0x402ec0, argc=2, argv=0x7fffffffe938, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>,
    stack_end=0x7fffffffe928) at libc-start.c:287
        result = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {0, 17383474773081810, 4219669, 140737488349488, 0, 0, -17383475093979438, -17399103454069038},
              mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x410220, 0x7fffffffe938}, data = {prev = 0x0, cleanup = 0x0, canceltype = 4260384}}}
        not_first_call = <optimized out>
#14 0x000000000040633e in ?? ()
No symbol table info available.


The card is:

 $ opensc-tool -n
 Using reader with a card: OMNIKEY CardMan 6121 00 00
 CardOS M4
 $ opensc-tool -a

The same pkcs11-tool command works with another 'CardOS M4' card on the
same reader, so it must be something with the card's contents.

So far the only strangeness is the following. The working card has
matching sets of private, public key and certificate files. The problem
card has several of those too, plus a set consisting of only a private
and a public key (no certificate). In the past a bank employee had
problems putting a new "e-certificate" on the card, and the broken set
is probably a remnant from that time. Anyway, version 0.14.0-2 had no
problems working with that.

I tried to look at the code, but found out that the sc_pkcs15_dup_pubkey
function that invoces the assert() is new in version 0.15.0. Whatever
was doing its job in 0.14.0 works.

I hope this information is enough, but I am ready to provide more if
necessary.

Enabling 'debug = 9' in opensc.conf produces a lot of output, here's
the tail:

0x7f7e0d56a700 16:02:04.317 [opensc-pkcs11] card.c:727:sc_read_record: called
0x7f7e0d56a700 16:02:04.317 [opensc-pkcs11] apdu.c:563:sc_transmit_apdu: called
0x7f7e0d56a700 16:02:04.317 [opensc-pkcs11] card.c:352:sc_lock: called
0x7f7e0d56a700 16:02:04.317 [opensc-pkcs11] apdu.c:530:sc_transmit: called
0x7f7e0d56a700 16:02:04.317 [opensc-pkcs11] apdu.c:384:sc_single_transmit: called
0x7f7e0d56a700 16:02:04.317 [opensc-pkcs11] apdu.c:389:sc_single_transmit: CLA:0, INS:B2, P1:1, P2:4, data(0) (nil)
0x7f7e0d56a700 16:02:04.317 [opensc-pkcs11] reader-pcsc.c:251:pcsc_transmit: reader 'OMNIKEY CardMan 6121 00 00'
0x7f7e0d56a700 16:02:04.317 [opensc-pkcs11] apdu.c:187:sc_apdu_log:
Outgoing APDU data [    5 bytes] =====================================
00 B2 01 04 00 .....
======================================================================
0x7f7e0d56a700 16:02:04.317 [opensc-pkcs11] reader-pcsc.c:184:pcsc_internal_transmit: called
0x7f7e0d56a700 16:02:04.322 [opensc-pkcs11] apdu.c:187:sc_apdu_log:
Incoming APDU data [    2 bytes] =====================================
6A 83 j.
======================================================================
0x7f7e0d56a700 16:02:04.322 [opensc-pkcs11] apdu.c:399:sc_single_transmit: returning with: 0 (Success)
0x7f7e0d56a700 16:02:04.322 [opensc-pkcs11] apdu.c:552:sc_transmit: returning with: 0 (Success)
0x7f7e0d56a700 16:02:04.322 [opensc-pkcs11] card.c:392:sc_unlock: called
0x7f7e0d56a700 16:02:04.322 [opensc-pkcs11] card-cardos.c:278:cardos_check_sw: record not found
0x7f7e0d56a700 16:02:04.322 [opensc-pkcs11] iso7816.c:210:iso7816_read_record: returning with: -1202 (Record not found)
0x7f7e0d56a700 16:02:04.322 [opensc-pkcs11] card.c:733:sc_read_record: returning with: -1202 (Record not found)
0x7f7e0d56a700 16:02:04.322 [opensc-pkcs11] card.c:392:sc_unlock: called
0x7f7e0d56a700 16:02:04.322 [opensc-pkcs11] reader-pcsc.c:556:pcsc_unlock: called
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15.c:2397:sc_pkcs15_read_file: returning with: 0 (Success)
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15.c:2098:sc_pkcs15_parse_df: returning with: 0 (Success)
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] framework-pkcs15.c:728:pkcs15_create_pkcs11_objects: Found 0 data objects
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] framework-pkcs15.c:836:pkcs15_bind_related_objects: Looking for objects related to object 0
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] framework-pkcs15.c:743:__pkcs15_prkey_bind_related: Object is a private key and has id 69f9f837c4ef0c6eae38d61873dde123da79343a
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] framework-pkcs15.c:768:__pkcs15_prkey_bind_related: Associating object 6 as public key
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15-algo.c:530:sc_asn1_encode_algorithm_id: called
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15-algo.c:531:sc_asn1_encode_algorithm_id: type of algorithm to encode: 0
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15-algo.c:545:sc_asn1_encode_algorithm_id: encode algo 1.2.840.113549.1.1.1
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1546:asn1_encode_entry:  encoding 'algorithm'
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1551:asn1_encode_entry:  type=6, tag=0x06, parm=0xc138f4, len=0
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1729:asn1_encode_entry:  length of encoded item=11
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1546:asn1_encode_entry:  encoding 'nullParam'
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1551:asn1_encode_entry:  type=5, tag=0x05, parm=(nil), len=0
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1729:asn1_encode_entry:  length of encoded item=2
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15-algo.c:580:sc_asn1_encode_algorithm_id: return encoded algorithm ID: 06092A864886F70D0101010500
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15-algo.c:581:sc_asn1_encode_algorithm_id: returning with: 0 (Success)
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15-algo.c:489:sc_asn1_decode_algorithm_id: called
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1443:asn1_decode:  called, left=13, depth 1
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1467:asn1_decode: Looking for 'algorithm', tag 0x6
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1259:asn1_decode_entry:  decoding 'algorithm'
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1467:asn1_decode: Looking for 'nullParam', tag 0x5, OPTIONAL
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1259:asn1_decode_entry:  decoding 'nullParam'
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] asn1.c:1516:asn1_decode: returning with: 0 (Success)
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15-algo.c:497:sc_asn1_decode_algorithm_id: decoded OID '1.2.840.113549.1.1.1'
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15-algo.c:514:sc_asn1_decode_algorithm_id: returning with: 0 (Success)
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] pkcs15-pubkey.c:1131:sc_pkcs15_dup_pubkey: returning with: 0 (Success)
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] framework-pkcs15.c:836:pkcs15_bind_related_objects: Looking for objects related to object 1
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] framework-pkcs15.c:743:__pkcs15_prkey_bind_related: Object is a private key and has id b05340a04f8a678d0058912ca1ac4c92037d7068
0x7f7e0d56a700 16:02:04.326 [opensc-pkcs11] framework-pkcs15.c:768:__pkcs15_prkey_bind_related: Associating object 7 as public key
pkcs11-tool: pkcs15-pubkey.c:1064: sc_pkcs15_dup_pubkey: Assertion `key && out' failed.
zsh: abort      pkcs11-tool -O

b05340a04f8a678d0058912ca1ac4c92037d7068 is indeed the ID of the
private and public keys that have no matching certificate file.


HTH,
    dam