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]

Marte Myrvold said:

Can you upload the complete device log?

There are no other NFC library related related logs. Below you have a complete sequence with my application logs and my notes about what's happening. 

[00:00:33.404,754] <wrn> app: ***** NFC enable T4T APDU ******
[00:00:33.404,876] <wrn> app: nfcmgr : type 4 APDU started, fwi=8

->FWI is set successfully to 8 (==77ms FWT)

[00:00:44.111,541] <wrn> app: nfc_requestor : NFC field on for APDU routing START

->Got NFC_T4T_EVENT_FIELD_ON event in callback

[00:00:44.151,153] <wrn> app: nfcmgr:cmd rx'd

-> NFC_T4T_EVENT_DATA_IND gives us apdu in the callback, the command processing is scheduled on system work queue. Note: the data buffer given in the callback is copied by my application code.

[00:00:44.151,275] <wrn> app: nfcmgr:cmd process start

-> processing the command starts

[00:00:44.186,767] <wrn> app: nfc_requestor : NFC APDU routed OK cmd (00a4040007d276000085010100) response (90:00 le=2)
[00:00:44.186,828] <wrn> app: nfcmgr:cmd process ok, call response_pdu_send()

-> processing of command took 35ms, got a response (9000), calls the nfc lib to send the response.

[00:00:44.186,950] <wrn> app: nfcmgr:cmd rx@44151, process@44151, resp@44186, now@44186

-> some stats after returning from sending response. Note it took 35ms to process the command (on the system work queue), so response sent well within the 77ms timeout.

[00:00:45.261,840] <wrn> app: nfcmgr: free waiting
[00:00:45.261,932] <wrn> app: nfc_requestor : NFC field off for APDU routing END

-> my code frees the response buffer because the callback was called with a NFC_T4T_EVENT_FIELD_OFF event, presumably because the reader gave up! No "data transmitted event" received at this time...  Note the time delta from send to end of field is about 75ms and about 110ms from the command reception.

[00:00:45.521,636] <wrn> app: nfc_requestor : NFC field on for APDU routing START

-> reader tries again

[00:00:45.523,223] <wrn> app: nfcmgr: data tx event

-> and NOW we get the NFC_T4T_EVENT_DATA_TRANSMITTED event !! Why?

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

-> and this error from platform_internal_thread.c/cb_work() because it ran out of ring buffer data somehow?

[00:00:45.562,469] <wrn> app: nfcmgr:cmd rx'd

-> but continues, and we get the new command APDU anyway, which basically repeats the same sequence.

[00:00:45.562,591] <wrn> app: nfcmgr:cmd process start
[00:00:45.598,083] <wrn> app: nfc_requestor : NFC APDU routed OK cmd (00a4040007d276000085010100) response (90:00 le=2)
[00:00:45.598,144] <wrn> app: nfcmgr:cmd process ok, call response_pdu_send()
[00:00:45.598,266] <wrn> app: nfcmgr:cmd rx@45562, process@45562, resp@45598, now@45598
[00:00:46.678,588] <wrn> app: nfcmgr: free waiting
[00:00:46.678,680] <wrn> app: nfc_requestor : NFC field off for APDU routing END

This is what happens every time if the command processing takes longer than about 3ms....

Hopefully someone internally can help to understand what is going on....

Note:

- I have checked that the ring buffer is not full (the assert()s in the platform code do not trigger)

- I had to increase the size for the CONFIG_NFC_LIB_CTX_MAX_SIZE from the default of 16 to 128, otherwise the assert here in cb_work() would also sometimes trigger (but only when this problem of long processing occurred.... maybe a clue?)

    __ASSERT(header.ctx_size <= NFC_LIB_CTX_SIZE, "NFC context is bigger than expected.");