Topic: Works only second run. Bug ?

Hello All,


Few days ago I started some development with RFID and libnfc.
I encountered weird problem related to my PN532_uart reader (Adafruits board)
For past two days everything seems to work ok, and then after system kernel upgrade (2.6.32 -> 3.1.10) weird thing started to happend.

Exactly every second run I success with nfc-poll, nfc-mfclassic and other is failure. You will find sample session below.
I was thinking that this might be a kernel problem but after switch back to old one problem still exists :-) I've tried to build nfc 1.4.2, 1.5.x 1.6(rc).
I started suspec my reader that it is broken..is it possible with such symptoms ?
This looks somehow related to sending data over USB, but I tried different USB-UART chips (PL2302, FT232RL). No success, and problem sill exists.
When running strace on nfc-pool results are:

For OK:
open("/dev/ttyUSB0", O_RDWR|O_NOCTTY|O_NONBLOCK) = 3
[cut some stuff]
write(3, "\0\0\377\3\375\324\24\1\27\0", 10) = 10
select(4, [3], NULL, NULL, {1, 0})      = 1 (in [3], left {0, 996974})

For BAD attempt this looks like this:
open("/dev/ttyUSB0", O_RDWR|O_NOCTTY|O_NONBLOCK) = 3
write(3, "\0\0\377\3\375\324\24\1\27\0", 10) = 10
select(4, [3], NULL, NULL, {1, 0})      = 0 (Timeout)

Does anybody had similar symptoms ?
I' looked in code  for maybe  some not closed usb descriptors,etc...everything seems to be ok. The only tool that is working almost always is pn53x-diagnose.
Below sample session: smile
spock@aone ~/libnfc-read-only % nfc-poll
nfc-poll uses libnfc 1.6.0-rc1 (r1327)
nfc-poll: ERROR: Unable to open NFC device.
spock@aone ~/libnfc-read-only % nfc-poll
nfc-poll uses libnfc 1.6.0-rc1 (r1327)
NFC reader: pn532_uart:/dev/ttyUSB0 - PN532 v1.6 (0x07) opened
NFC device will poll during 30000 ms (20 pollings of 300 ms for 5 modulations)
^Cnfc_initiator_poll_target: Success
spock@aone ~/libnfc-read-only % nfc-poll
nfc-poll uses libnfc 1.6.0-rc1 (r1327)
nfc-poll: ERROR: Unable to open NFC device.
spock@aone ~/libnfc-read-only % nfc-poll
nfc-poll uses libnfc 1.6.0-rc1 (r1327)
NFC reader: pn532_uart:/dev/ttyUSB0 - PN532 v1.6 (0x07) opened
NFC device will poll during 30000 ms (20 pollings of 300 ms for 5 modulations)
^Cnfc_initiator_poll_target: Success
spock@aone ~/libnfc-read-only %
spock@aone ~/libnfc-read-only % nfc-poll
nfc-poll uses libnfc 1.6.0-rc1 (r1327)
nfc-poll: ERROR: Unable to open NFC device.
spock@aone ~/libnfc-read-only % nfc-poll
nfc-poll uses libnfc 1.6.0-rc1 (r1327)
NFC reader: pn532_uart:/dev/ttyUSB0 - PN532 v1.6 (0x07) opened
NFC device will poll during 30000 ms (20 pollings of 300 ms for 5 modulations)
^Cnfc_initiator_poll_target: Success
spock@aone ~/libnfc-read-only % nfc-poll
nfc-poll uses libnfc 1.6.0-rc1 (r1327)
nfc-poll: ERROR: Unable to open NFC device.
spock@aone ~/libnfc-read-only % nfc-poll
nfc-poll uses libnfc 1.6.0-rc1 (r1327)
NFC reader: pn532_uart:/dev/ttyUSB0 - PN532 v1.6 (0x07) opened
NFC device will poll during 30000 ms (20 pollings of 300 ms for 5 modulations)
^Cnfc_initiator_poll_target: Success
spock@aone ~/libnfc-read-only % nfc-poll
nfc-poll uses libnfc 1.6.0-rc1 (r1327)
nfc-poll: ERROR: Unable to open NFC device.
spock@aone ~/libnfc-read-only % pn53x-diagnose
pn53x-diagnose uses libnfc 1.6.0-rc1 (r1327)
NFC device [pn532_uart:/dev/ttyUSB0 - PN532 v1.6 (0x07)] opened.
Communication line test: OK
ROM test: OK
RAM test: OK
spock@aone ~/libnfc-read-only % pn53x-diagnose
pn53x-diagnose uses libnfc 1.6.0-rc1 (r1327)
NFC device [pn532_uart:/dev/ttyUSB0 - PN532 v1.6 (0x07)] opened.
Communication line test: OK
ROM test: OK
RAM test: OK

Spock
Thanks is advance.

Re: Works only second run. Bug ?

Maybe this will be usefull:
Result with --enable-debug:

nfc-poll uses libnfc 1.6.0-rc1 (r1327)
trace    libnfc.driver.pn532_uart    Trying to find PN532 device on serial port: /dev/ttyUSB0 at 115200 bauds.
trace    libnfc.bus.uart    Serial port speed requested to be set to 115200 bauds.
trace    libnfc.chip.pn53x    Diagnose
trace    libnfc.chip.pn53x    Timeout values: 500
trace    libnfc.bus.uart    TX: 55  55  00  00  00 
trace    libnfc.chip.pn53x    SAMConfiguration
trace    libnfc.chip.pn53x    Timeout values: 1000
trace    libnfc.bus.uart    TX: 00  00  ff  03  fd  d4  14  01  17  00 
trace    libnfc.bus.uart    Timeout!
error    libnfc.driver.pn532_uart    Unable to read ACK
trace    libnfc.driver.pn532_uart    Trying to find PN532 device on serial port: /dev/ttyS3 at 115200 bauds.
trace    libnfc.driver.pn532_uart    Trying to find PN532 device on serial port: /dev/ttyS2 at 115200 bauds.
trace    libnfc.driver.pn532_uart    Trying to find PN532 device on serial port: /dev/ttyS1 at 115200 bauds.
trace    libnfc.driver.pn532_uart    Trying to find PN532 device on serial port: /dev/ttyS0 at 115200 bauds.
trace    libnfc.general    0 device(s) found using pn532_uart driver
nfc-poll: ERROR nfc-poll.c:111
nfc-poll:     Unable to open NFC device.

Re: Works only second run. Bug ?

Hi,

Did you find the problem source ?

Romuald Conty

Re: Works only second run. Bug ?

Hi,

I am having the exact same problem as Spock. I have an Adafruits board connected via a USB-to-Serial converter on ttyUSB0.

The first attempt always results in a uart timeout (same debug messages as Spock), whilst the second attempt always works. The third attempt fails again, then the fourth attempt works. Etc, Etc. I made 30 straight attempts, and exactly 15 failed and 15 succeeded, in alternating order.

Something that may be relevant. Like Spock, "pn53x-diagnose" will work every time if run by itself, but if I run a successful "nfc-poll" and then run "pn53x-diagnose" immediately after, it will also fail, but if I run it a second time, it will work again.

I have also run "lsnfc" from nfcutils, and have the same issue. The first run fails with "ERROR: No device found", the second run find the device. The third run fails, fourth run finds the device again. Etc Etc.

Spock, did you ever find a solution to your problem?


Thanks,

Lachlan.


I am running Debian 6 with kernel 3.4.0.

5 (edited by Spock 2012-05-02 08:30:56)

Re: Works only second run. Bug ?

No,

Bug still exists. I tried different PC, different hardware arch (x86/arm), kernel (2.6.x,3.x) and symptoms are exactly the same. I can try to compile libnfc for mips and check if this is worth something, but I'm pretty sure that there still be a problem.

What I want to do this week is not to use USB/UART converter but connect device to hardware serial port I have on one of my linux based arm board.

What is also interesting that if I enable debug mode problem occurs much less frequently.

I also looked into source code (but I'm not uber C guru :) ), and I tend to believe that this is something within kernel USB stack not library itself..

Maybe this is realated to latest firmware on PN532 chip ?

baylf2000:
Did you used USB/UART cable or you connected your board via "hardware" RS-232 with level converter (MAX232 i.e) ?

6 (edited by yobibe 2012-05-02 12:05:06)

Re: Works only second run. Bug ?

Hi guys,

Does one of you have the material to sniff on the serial link?
When writing to /dev/ttyUSB0 and failing to get an answer, does the command comes to the PN532 at all or not?

If not, this can be the handling of USB data toggle bit upon set_configuration which doesn't get reset (bug in the USB/UART converter?) and then behavior depends on the number of messages of the previous session => maybe pn53x-diagnose always sends an even number of messages and T=0 every time a new session starts and the other commands have an odd number of messages => T=1 (& failure) then T=0 (ok) then T=1 etc

If yes and the PN532 doesn't reply, then the problem is more likely to be in the PN532 state, maybe it's busy and needs an ACK to reply again?

I don't have a setup like yours so I cannot test myself, just guessing...

Phil

7 (edited by Spock 2012-05-02 12:12:50)

Re: Works only second run. Bug ?

Yobibe,

Another possible source of problem worth to check - thanks.

I have oscilloscope, BusPirate, and access to Logic Analyser at my work. Thanks for suggestions. I will try to check this in next few days.

Marcin,

Re: Works only second run. Bug ?

Have a look into the code of pn53x_usb.c (https://code.google.com/p/libnfc/source … n53x_usb.c) and search for HACK1 & HACK2 around line 414.
They describe workarounds for the two problems I mentioned.

HACK1: always send an ACK to the chip when starting a session
HACK2: ensure we don't hit the T=1 bug of the PN533 (here you're not using the USB stack of PN532 as tehre is not, you're using USB stack of your converter but maybe it has the same bug)

Phil

9 (edited by Spock 2012-05-02 12:35:50)

Re: Works only second run. Bug ?

Yobibe,

That is why first I want to check "real" UART not USB/UART converter to get more data what layer might be a problem.
If problem will still exist then it is not USB kernel stack, and pn53x_usb.c will be next to close look smile

I just got CP2102 USB-UART converter since I read on some other post that some people have problems with FT2323RL and not using this one  (but PL2303) helps. I have PL2303 cable but problem is on both chips.

Thanks for initial place to look for.

So there are some issues to check:
- check with different USB/UART IC
- check with "real" UART (/dev/ttyS..)
- sniff UART transmission to see does communication requested by library indeed is recieved by PN532 and No messages/per session.

A little work for next few days/weekend, but weather in Poland is soo good ..
Tough choice smile

Marcin,