Using NFC Library in 'raw' APDU mode : how to set FWI/FWTX?

[BrianW]

Custom device using nrf5340, with NFC card emulation functionality.

To use the NFC, I understand that I should use the supplied nfc_t4t library (binary) and its api. I have this working ok for type 4 card emulation using the NDEF application functionality built in to the library..

I now need to create an application that will emulate other functions, and so I am trying to the use the library in 'raw APDU' mode. This is basically working, but I have run into a timeout issue : certain elements of my APDU processing can take some 10's of ms, and this is apparently causing my nfc reader to timeout its request. This causes the library to have some issues : I get logs like this:

[00:05:13.375,488] <err> nfc_platform: Tried to read data pointer: 4 bytes, read 0.
[00:05:13.375,488] <err> nfc_platform: Reading nfc ring buffer failed, resetting ring buffer.

 I think these are basically when I do the nfc_t4t_response_pdu_send() call to send the response PDU. Any ideas on what this means for my operation?

The reader never manages to get a valid response, this seems to be related to the time it takes for my code to process the APDU (around 35ms for a basic select operation, due to it being sent to a ISO7816 contact card for processing...). In the NFC spec I see this:

"When the Card Emulator needs more time than the defined FWT to process the received block, it uses an S(WTX) request for a waiting time extension. An S(WTX) request contains a 1-byte INF field as specified in Table 84"

How can I tell the library that I want it to send this S(WTX) frame? It seems it needs to be sent for each received command? The only param I see to set is the FWI (which sets the max FWT as I understand it). When I try to set this to the max (before doing nfc_t4t_setup()) :

                uint32_t fwi = NFC_T4T_FWI_MAX_VAL_EMV;

                if ((ret=nfc_t4t_parameter_set(NFC_T4T_PARAM_FWI, &fwi, sizeof(fwi)))!=0) {

                    log_warn("nfcmgr: t4t fwi set fails (%d)",ret);

                }

Then it gives me an error -22

Doing a get of the FWI_MAX says its set to 4.

Is there a way to get the library to tell the reader that I want to increase the waiting timeout for a specific received command?

thanks

[BrianW]

BrianW said:

Then it gives me an error -22

Ok, I have fixed my problem with nfc_t4t_parameter_set(), it needs the parameter value to be a uint8_t.

So now I can set the FWI to be 8 max. By my calculation, this should make the reader apply a FWT of around 77ms

(FWT = (256 x 16/Fc) x 2^FWI, Fc=13.56MHz, FWI=8 -> 77ms)

The FWI is correctly taken into acount on the reader (it reports it as 8, and calculates the FWT=77ms)

However, any delay in responding that is over 2-3ms fail to work.... and gets the same logs:

[00:05:13.375,488] <err> nfc_platform: Tried to read data pointer: 4 bytes, read 0.
[00:05:13.375,488] <err> nfc_platform: Reading nfc ring buffer failed, resetting ring buffer.

So, maybe its not the reader timing out, but the library? Can anyone shed some light on the this lib? As its supplied only as a binary blob, I can't see what is actually happening....

[Marte Myrvold]

Hi,

Great to hear that you fixed the problem with nfc_t4t_parameter_set().

I will ask about the other issue internally. Can you upload the complete device log?

Best regards,
Marte

[BrianW]

With a little more logging info (including the contents of the buffers), I think the library is not accepting my response, and the tx of size 3 is in fact a WTX S-block of some kind around the timeout time (occurs 85ms after the reception of the command).

[00:04:09.985,107] <inf> NRFX_NFCT: Field detected
[00:04:09.998,809] <inf> NRFX_NFCT: Selected
[00:04:09.998,901] <wrn> app: nfc_requestor : NFC field on for APDU routing START
[00:04:09.998,992] <wrn> app: ISO7816: START - card already open
[00:04:09.999,786] <inf> NRFX_NFCT: Rx fend evt (2) [05 78 ]
[00:04:09.999,877] <inf> NRFX_NFCT: Tx start evt (5) [05 78 80 82 02 ]
[00:04:10.000,427] <inf> NRFX_NFCT: Tx fend evt (5)
[00:04:10.010,345] <inf> NRFX_NFCT: Rx fend evt (1) [c2 ]
[00:04:10.010,375] <inf> NRFX_NFCT: Tx start evt (1) [c2 ]
[00:04:10.010,620] <inf> NRFX_NFCT: Tx fend evt (1)
[00:04:10.019,409] <inf> NRFX_NFCT: Selected
[00:04:10.020,385] <inf> NRFX_NFCT: Rx fend evt (2) [05 78 ]
[00:04:10.020,477] <inf> NRFX_NFCT: Tx start evt (5) [05 78 80 82 02 ]
[00:04:10.020,996] <inf> NRFX_NFCT: Tx fend evt (5)
[00:04:10.027,130] <inf> NRFX_NFCT: Rx fend evt (14) [02 00 a4 04 00 07 d2 76 00 00 85 01 01 00 ]
[00:04:10.031,799] <inf> NRFX_NFCT: Tx start evt (2) [f2 01 ]
[00:04:10.032,104] <inf> NRFX_NFCT: Tx fend evt (2)
[00:04:10.033,050] <inf> NRFX_NFCT: Rx fend evt (2) [f2 01 ]
[00:04:10.063,293] <inf> app: iso7816: cmd (00:A4:04:00 lc=7, le=0) sent OK, response (6A:82 le=0) bytes
[00:04:10.063,385] <inf> app: ISO7816: routing PROCESS (next) returns successful response of size 2

[00:04:10.063,629] <wrn> app: nfc_requestor : NFC APDU routed OK cmd (00a4040007d276000085010100) response (6A:82 le=2)
[00:04:10.063,751] <wrn> app: nfcmgr:cmd rx@250027, process@250027, resp@250063, now@250063
[00:04:10.110,351] <inf> NRFX_NFCT: Tx start evt (2) [f2 01 ]
[00:04:10.110,656] <inf> NRFX_NFCT: Tx fend evt (2)
[00:04:10.111,633] <inf> NRFX_NFCT: Rx fend evt (2) [f2 01 ]
[00:04:10.111,694] <inf> NRFX_NFCT: Tx start evt (3) [f2 01 91 ]
[00:04:10.112,091] <inf> NRFX_NFCT: Tx fend evt (3)
[00:04:10.113,037] <inf> NRFX_NFCT: Rx fend evt (2) [f2 11 ]
[00:04:11.049,316] <inf> NRFX_NFCT: Field lost
[00:04:11.049,438] <wrn> app: nfc_requestor : NFC field off for APDU routing END
[00:04:11.049,530] <inf> app: ISO7816: routing END

I see the ATS being sent (twice...) as TL T0 TA TB TC ( values 05 78 80 82 02 look reasonable, and set the FWI to 8 as expected)

Then the tx of [f2 02] and rx of same are the S-block WTX request and responses...

But I can't understand 

- why no sending of the response I submit to the library (at 4:10:063 timestamp, 36ms after the command was received)

- the last S-block of length 3  [f2 01 91] - what is the extra byte of 0x91? and the response of [f2 11] is a protocol error for me!

 

[tesc]

Hi,

This seems to be related to a known issue which was patched prior to nRF Connect SDK v2.9.0 (which from what I understand is the version you are using.)

It seems to happen when the application attempts to transmit a response PDU, while the transmission of an S(WTX) block has already started.

We need to look further into the issue, and will get back to you when we know more or if we are in need of more information for reproducing the issue in our end.

Regards,
Terje

[BrianW]

tesc said:

nRF Connect SDK v2.9.0 (which from what I understand is the version you are using.)

Correct. 

tesc said:

We need to look further into the issue, and will get back to you when we know more or if we are in need of more information for reproducing the issue in our end.

Ok, thats great. Hopefully we can find out how to get this fixed... 

By the way, what is the reason for not providing the nfc lib as source (as then I could at least try to debug it myself)?

[tesc]

Hi,

BrianW said:

Ok, thats great. Hopefully we can find out how to get this fixed

What we see initially, is that it looks like the 3-byte Tx frame logged is the corrupted frame. Due to key persons away at the moment, I am afraid further inquiry might delay until well into August when they are back. I am sorry for any inconvenience.

BrianW said:

what is the reason for not providing the nfc lib as source

Licensing terms from a third party prevents us from sharing the source code with others. The library is therefore shared in compiled binary form only.

Regards,
Terje

[BrianW]

Hi Terje, Any news from the dev team?

thanks

[tesc]

Hi,

Not yet, I am afraid. I will keep you informed when I know more.

Regards,
Terje

[tesc]

Hi,

I have some feedback now, that your modifications to platform.c might be invalid. If you disable CONFIG_NFC_THREAD_CALLBACK this should bypass platform.c, which should reveal if the error is in the library itself.

Regards,
Terje

[BrianW]

I'm very doubtfull about this, as my changes to platform.c/platform_internal_thread.c were made to add debugging to see if there was an issue about the ring buffer/scheduling or not...(and there are some issues).

I will need to come back to the project and see what happens when I rebuild with this option.

What happened to this investigation?

tesc said:

What we see initially, is that it looks like the 3-byte Tx frame logged is the corrupted frame

[BrianW]

tesc said:

disable CONFIG_NFC_THREAD_CALLBACK this should bypass platform.c, which should reveal if the error is in the library itself.

This option

CONFIG_NFC_THREAD_CALLBACK=n

causes the code to crash immediately the NFC reader is presented. Do I need other config set or other code changes?

[BrianW]

Ok, I see that this option essentially calls my code in the IRQ context directly using platform_internal_irq.c - not surprising it ends up in an assert().

By creating a 'test' callback function which is IRQ safe, and just makes a fixed response to the DATA_IND event using nfc_t4t_response_pdu_send() , the reader operates as expected.

However, if there is any delay (more than a couple of ms) in generating the response (eg I use the system queue to schedule the response outside of the callback) then the reader does not manage to see the response correctly.

I think this demonstrates that the problem is not in the platform.c or platform_internal.c code but in the library (as already hinted at in your previous responses).

My callback code for the build case with CONFIG_NFC_THREAD_CALLBACK=n:

static uint8_t _nok_resp[] = { 0x6a, 0x82};

static void _apdu_cmd_test_resp(void* p_ctx) {

    struct _nfc_ctx* ctx = (struct _nfc_ctx*)p_ctx;

    if (ctx==NULL) {

        return;

    }

    int ret;

    if ((ret=nfc_t4t_response_pdu_send(_nok_resp, sizeof(_nok_resp)))!=0) {

        log_warn("nfcmgr: t4t apdu test resp NOT sent after %dms error (%d)", (gettime_ms()-ctx->lastRead), ret);

    } else {

        log_warn("nfcmgr:t4t apdu test resp sent after %dms", (gettime_ms()-ctx->lastRead));

    }

}

static void _apdu_cmd_test_print(void* p_ctx) {

    log_warn("nfcmgr: test event %d", (int32_t)p_ctx);

}

// ADPU type operation test callback, called directly on IRQ, just always responds with 'no'

static void _nfc_t4t_test_cb_from_irq(void *context, nfc_t4t_event_t event, const uint8_t *data, size_t data_length, uint32_t flags) {

    struct _nfc_ctx* ctx = (struct _nfc_ctx*)context;

    if (ctx==NULL) {

        return;

    }

    switch(event) {        

        case NFC_T4T_EVENT_FIELD_ON: {

            ctx->nfc_active = true;

            wsched_request(_apdu_cmd_test_print, (void*)NFC_T4T_EVENT_FIELD_ON);

            break;

        }

        case NFC_T4T_EVENT_FIELD_OFF: {

            ///< External Reader polling stopped

            ctx->nfc_active = false;

            wsched_request(_apdu_cmd_test_print, (void*)NFC_T4T_EVENT_FIELD_OFF);

            break;

        }

        case NFC_T4T_EVENT_DATA_IND: {

            ctx->lastRead = gettime_ms();

            int ret=nfc_t4t_response_pdu_send(_nok_resp, sizeof(_nok_resp));

            wsched_request(_apdu_cmd_test_print, (void*)ret);

//            wsched_request(_apdu_cmd_test_print, (void*)NFC_T4T_EVENT_DATA_IND);

            // will generate a response

//            wsched_request(_apdu_cmd_test_resp, ctx);

            break;

        }

        case NFC_T4T_EVENT_DATA_TRANSMITTED: {

            // just to log

            wsched_request(_apdu_cmd_test_print, (void*)NFC_T4T_EVENT_DATA_TRANSMITTED);

            break;

        }

        default: {

            wsched_request(_apdu_cmd_test_print, (void*)event);

            break;

        }

    }

}

Note if the case for DATA_IND uses the  system work queue to schedule the  function _apdu_cmd_test_resp()  then the problem occurs, if it directly does pdu_send() then it does not.