This is the output of nfcpy:
2011-07-26 17:10:44,491 - nfc.llcp.tco - DEBUG - 1866 - tco.py:341 - DLC (16,None) LISTEN dequeue CC PDU
2011-07-26 17:10:44,491 - nfc.llcp.llc - DEBUG - 1866 - llc.py:279 - SEND 16 -> 33 CC MIU=128 RW=2
2011-07-26 17:10:44,492 - nfc.dev.pn53x - DEBUG - 1866 - pn53x.py:200 - write 8 byte
0000: d4 40 01 85 90 05 01 02 .@......
2011-07-26 17:10:44,558 - nfc.dev.pn53x - DEBUG - 1866 - pn53x.py:220 - read 92 byte
0000: d5 41 00 43 21 00 01 00 00 00 01 01 00 00 00 4c .A.C!..........L
0010: d2 13 36 61 70 70 6c 69 63 61 74 69 6f 6e 2f 6d ..6application/m
0020: 54 72 6f 63 6f 73 7b 22 63 22 3a 22 67 53 58 6a Trocos{"c":"gSXj
0030: 36 61 59 41 45 4b 65 50 50 45 6f 71 43 72 6c 73 6aYAEKePPEoqCrls
0040: 70 70 4e 36 6e 56 50 41 72 4f 79 68 76 39 4d 50 ppN6nVPArOyhv9MP
0050: 70 5a 44 4b 69 52 77 3d 5c 6e 22 7d pZDKiRw=\n"}
2011-07-26 17:10:44,559 - nfc.llcp.llc - DEBUG - 1866 - llc.py:290 - RECV 33 -> 16 I N(S)=0 N(R)=0 LEN=86 SDU=0100000001010000004cd213366170706c69636174696f6e2f6d54726f636f737b2263223a226753586a36615941454b655050456f7143726c7370704e366e565041724f796876394d50705a444b6952773d5c6e227d
2011-07-26 17:10:44,559 - nfc.llcp.tco - DEBUG - 1866 - tco.py:341 - DLC (16,33) ESTABLISHED enqueue I PDU
2011-07-26 17:10:44,560 - nfc.llcp.tco - DEBUG - 1866 - tco.py:341 - DLC (16,33) ESTABLISHED voluntary ack DLC 16 <-> 33 ESTABLISHED RW(R)=1 V(S)=0 V(SA)=0 RW(L)=2 V(R)=1 V(RA)=0
2011-07-26 17:10:44,560 - nfc.llcp.llc - DEBUG - 1866 - llc.py:279 - SEND 16 -> 33 RR N(R)=1
2011-07-26 17:10:44,560 - nfc.dev.pn53x - DEBUG - 1866 - pn53x.py:200 - write 6 byte
0000: d4 40 01 87 50 01 [email protected].
2011-07-26 17:10:44,566 - nfc.dev.pn53x - DEBUG - 1866 - pn53x.py:220 - read 3 byte
0000: d5 41 0a .A.
2011-07-26 17:10:44,566 - nfc.llcp.llc - DEBUG - 1866 - llc.py:282 - in exchange => IOError [Errno 10] hardware error
2011-07-26 17:10:44,566 - nfc.llcp.llc - INFO - 1866 - llc.py:286 - shutdown on link disruption
2011-07-26 17:10:44,566 - nfc.llcp.llc - DEBUG - 1866 - llc.py:253 - closing service access point 16
2011-07-26 17:10:44,567 - nfc.llcp.llc - DEBUG - 1866 - llc.py:95 - shutdown socket DLC 16 <-> None LISTEN RW(R)=None V(S)=0 V(SA)=0 RW(L)=2 V(R)=0 V(RA)=0
2011-07-26 17:10:44,567 - nfc.llcp.tco - DEBUG - 1866 - tco.py:341 - DLC (None,None) LISTEN close()
2011-07-26 17:10:44,567 - nfc.llcp.llc - DEBUG - 1866 - llc.py:95 - shutdown socket DLC 16 <-> 33 ESTABLISHED RW(R)=1 V(S)=0 V(SA)=0 RW(L)=2 V(R)=1 V(RA)=1
2011-07-26 17:10:44,567 - nfc.llcp.tco - DEBUG - 1866 - tco.py:341 - DLC (None,33) ESTABLISHED close()
2011-07-26 17:10:44,570 - nfc.llcp.tco - DEBUG - 1866 - tco.py:341 - DLC (None,33) SHUTDOWN close()
2011-07-26 17:10:44,570 - nfc.llcp.tco - DEBUG - 1866 - tco.py:341 - DLC (None,None) SHUTDOWN close()
2011-07-26 17:10:44,571 - nfc.llcp.llc - DEBUG - 1866 - llc.py:253 - closing service access point 1
2011-07-26 17:10:44,571 - nfc.llcp.llc - DEBUG - 1866 - llc.py:253 - closing service access point 0
2011-07-26 17:10:44,571 - nfc.llcp.llc - DEBUG - 1866 - llc.py:335 - llc run thread terminated
Stack trace:
#4 0x080e0721 in call_function (f=
Frame 0xa0d556c, for file /usr/lib/python2.6/threading.py, line 239, in wait (self=<_Condition(_Condition__lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0xb745e6e0>, _RLock__count=0) at remote 0x9f5f52c>, acquire=<instancemethod at remote 0x987cb6c>, _is_owned=<instancemethod at remote 0x9f60d9c>, _release_save=<instancemethod at remote 0x987ce8c>, release=<instancemethod at remote 0x987ccfc>, _acquire_restore=<instancemethod at remote 0x9f60a04>, _Verbose__verbose=False, _Condition__waiters=[<thread.lock at remote 0xb745e6f0>]) at remote 0x9f5f72c>, timeout=None, waiter=<thread.lock at remote 0xb745e6f0>, saved_state=(2, -1254732944)), throwflag=0) at ../Python/ceval.c:3750
#5 PyEval_EvalFrameEx (f=
Frame 0xa0d556c, for file /usr/lib/python2.6/threading.py, line 239, in wait (self=<_Condition(_Condition__lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0xb745e6e0>, _RLock__count=0) at remote 0x9f5f52c>, acquire=<instancemethod at remote 0x987cb6c>, _is_owned=<instancemethod at remote 0x9f60d9c>, _release_save=<instancemethod at remote 0x987ce8c>, release=<instancemethod at remote 0x987ccfc>, _acquire_restore=<instancemethod at remote 0x9f60a04>, _Verbose__verbose=False, _Condition__waiters=[<thread.lock at remote 0xb745e6f0>]) at remote 0x9f5f72c>, timeout=None, waiter=<thread.lock at remote 0xb745e6f0>, saved_state=(2, -1254732944)), throwflag=0) at ../Python/ceval.c:2412
#6 0x080e2507 in PyEval_EvalCodeEx (co=0xb71f9410, globals=
{'current_thread': <function at remote 0xb7209f0c>, '_BoundedSemaphore': <type at remote 0x972c344>, 'currentThread': <function at remote 0xb7209f0c>, '_Timer': <type at remote 0x972cb2c>, '_format_exc': <function at remote 0xb71f18ec>, 'Semaphore': <function at remote 0xb7209304>, 'activeCount': <function at remote 0xb720a02c>, '_profile_hook': None, '_sleep': <built-in function sleep>, '_trace_hook': None, 'ThreadError': <type at remote 0x970fdfc>, '_enumerate': <function at remote 0xb720a064>, '_start_new_thread': <built-in function start_new_thread>, 'wraps': <function at remote 0xb71fde9c>, 'BoundedSemaphore': <function at remote 0xb720956c>, '_shutdown': <instancemethod at remote 0xb740861c>, '__all__': ['activeCount', 'active_count', 'Condition', 'currentThread', 'current_thread', 'enumerate', 'Event', 'Lock', 'RLock', 'Semaphore', 'BoundedSemaphore', 'Thread', 'Timer', 'setprofile', 'settrace', 'local', 'stack_size'], '_Event': <type at remote 0x972c7fc>, 'active_count': <function at remote 0xb720a02c...(truncated), locals=0x0, args=0xa0d53dc, argcount=1, kws=0xa0d53e0, kwcount=0, defs=0xb72077d8, defcount=1, closure=0x0) at ../Python/ceval.c:3000
#7 0x080e098b in fast_function (f=
Frame 0xa0d529c, for file /mnt/code/vmachine/nfcpy/nfc/llcp/tco.py, line 123, in recv (self=<DataLinkConnection(lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0xb745e6e0>, _RLock__count=0) at remote 0x9f5f52c>, send_buf=1, recv_miu=128, send_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cd4c>, _is_owned=<instancemethod at remote 0x9f609dc>, _release_save=<instancemethod at remote 0x987cdec>, release=<instancemethod at remote 0x987cd74>, _acquire_restore=<instancemethod at remote 0x987ccd4>, _Verbose__verbose=False, _Condition__waiters=[]) at remote 0x9f5f6cc>, send_win=None, recv_queue=<collections.deque at remote 0x9f5d144>, addr=32, recv_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cb6c>, _is_owned=<instancemethod at remote 0x9f60d9c>, _release_save=<instancemethod at remote 0x987ce8c>, release=<instancemethod at remote 0x987ccfc>, _acquire_restore=<instancemethod at remote 0x9f60a04>, _Ver...(truncated), throwflag=0) at ../Python/ceval.c:3846
#8 call_function (f=
Frame 0xa0d529c, for file /mnt/code/vmachine/nfcpy/nfc/llcp/tco.py, line 123, in recv (self=<DataLinkConnection(lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0xb745e6e0>, _RLock__count=0) at remote 0x9f5f52c>, send_buf=1, recv_miu=128, send_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cd4c>, _is_owned=<instancemethod at remote 0x9f609dc>, _release_save=<instancemethod at remote 0x987cdec>, release=<instancemethod at remote 0x987cd74>, _acquire_restore=<instancemethod at remote 0x987ccd4>, _Verbose__verbose=False, _Condition__waiters=[]) at remote 0x9f5f6cc>, send_win=None, recv_queue=<collections.deque at remote 0x9f5d144>, addr=32, recv_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cb6c>, _is_owned=<instancemethod at remote 0x9f60d9c>, _release_save=<instancemethod at remote 0x987ce8c>, release=<instancemethod at remote 0x987ccfc>, _acquire_restore=<instancemethod at remote 0x9f60a04>, _Ver...(truncated), throwflag=0) at ../Python/ceval.c:3771
---Type to continue, or q to quit---
#9 PyEval_EvalFrameEx (f=
Frame 0xa0d529c, for file /mnt/code/vmachine/nfcpy/nfc/llcp/tco.py, line 123, in recv (self=<DataLinkConnection(lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0xb745e6e0>, _RLock__count=0) at remote 0x9f5f52c>, send_buf=1, recv_miu=128, send_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cd4c>, _is_owned=<instancemethod at remote 0x9f609dc>, _release_save=<instancemethod at remote 0x987cdec>, release=<instancemethod at remote 0x987cd74>, _acquire_restore=<instancemethod at remote 0x987ccd4>, _Verbose__verbose=False, _Condition__waiters=[]) at remote 0x9f5f6cc>, send_win=None, recv_queue=<collections.deque at remote 0x9f5d144>, addr=32, recv_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cb6c>, _is_owned=<instancemethod at remote 0x9f60d9c>, _release_save=<instancemethod at remote 0x987ce8c>, release=<instancemethod at remote 0x987ccfc>, _acquire_restore=<instancemethod at remote 0x9f60a04>, _Ver...(truncated), throwflag=0) at ../Python/ceval.c:2412
#10 0x080e18b0 in fast_function (f=
Frame 0xa0e3374, for file /mnt/code/vmachine/nfcpy/nfc/llcp/tco.py, line 424, in connect (self=<DataLinkConnection(lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0xb745e6e0>, _RLock__count=0) at remote 0x9f5f52c>, send_buf=1, recv_miu=128, send_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cd4c>, _is_owned=<instancemethod at remote 0x9f609dc>, _release_save=<instancemethod at remote 0x987cdec>, release=<instancemethod at remote 0x987cd74>, _acquire_restore=<instancemethod at remote 0x987ccd4>, _Verbose__verbose=False, _Condition__waiters=[]) at remote 0x9f5f6cc>, send_win=None, recv_queue=<collections.deque at remote 0x9f5d144>, addr=32, recv_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cb6c>, _is_owned=<instancemethod at remote 0x9f60d9c>, _release_save=<instancemethod at remote 0x987ce8c>, release=<instancemethod at remote 0x987ccfc>, _acquire_restore=<instancemethod at remote 0x9f60a04>, _...(truncated), throwflag=0) at ../Python/ceval.c:3836
#11 call_function (f=
Frame 0xa0e3374, for file /mnt/code/vmachine/nfcpy/nfc/llcp/tco.py, line 424, in connect (self=<DataLinkConnection(lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0xb745e6e0>, _RLock__count=0) at remote 0x9f5f52c>, send_buf=1, recv_miu=128, send_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cd4c>, _is_owned=<instancemethod at remote 0x9f609dc>, _release_save=<instancemethod at remote 0x987cdec>, release=<instancemethod at remote 0x987cd74>, _acquire_restore=<instancemethod at remote 0x987ccd4>, _Verbose__verbose=False, _Condition__waiters=[]) at remote 0x9f5f6cc>, send_win=None, recv_queue=<collections.deque at remote 0x9f5d144>, addr=32, recv_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cb6c>, _is_owned=<instancemethod at remote 0x9f60d9c>, _release_save=<instancemethod at remote 0x987ce8c>, release=<instancemethod at remote 0x987ccfc>, _acquire_restore=<instancemethod at remote 0x9f60a04>, _...(truncated), throwflag=0) at ../Python/ceval.c:3771
#12 PyEval_EvalFrameEx (f=
Frame 0xa0e3374, for file /mnt/code/vmachine/nfcpy/nfc/llcp/tco.py, line 424, in connect (self=<DataLinkConnection(lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0xb745e6e0>, _RLock__count=0) at remote 0x9f5f52c>, send_buf=1, recv_miu=128, send_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cd4c>, _is_owned=<instancemethod at remote 0x9f609dc>, _release_save=<instancemethod at remote 0x987cdec>, release=<instancemethod at remote 0x987cd74>, _acquire_restore=<instancemethod at remote 0x987ccd4>, _Verbose__verbose=False, _Condition__waiters=[]) at remote 0x9f5f6cc>, send_win=None, recv_queue=<collections.deque at remote 0x9f5d144>, addr=32, recv_ready=<_Condition(_Condition__lock=<...>, acquire=<instancemethod at remote 0x987cb6c>, _is_owned=<instancemethod at remote 0x9f60d9c>, _release_save=<instancemethod at remote 0x987ce8c>, release=<instancemethod at remote 0x987ccfc>, _acquire_restore=<instancemethod at remote 0x9f60a04>, _...(truncated), throwflag=0) at ../Python/ceval.c:2412
#13 0x080e18b0 in fast_function (f=
Frame 0xa0e3084, for file /mnt/code/vmachine/nfcpy/nfc/llcp/llc.py, line 490, in connect (self=<LogicalLinkControl(_Thread__ident=-1271518352, _Thread__block=<_Condition(_Verbose__verbose=False, _Condition__lock=<thread.lock at remote 0xb745e640>, acquire=<built-in method acquire of thread.lock object at remote 0xb745e640>, _Condition__waiters=[], release=<built-in method release of thread.lock object at remote 0xb745e640>) at remote 0x9f5e92c>, _Thread__name='Thread-2', _Thread__daemonic=False, lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0xb745e650>, _RLock__count=0) at remote 0x9f5e96c>, snl={'urn:nfc:sn:snep': 4, 'urn:nfc:sn:ip': 2, 'urn:nfc:sn:sdp': 1, 'com.android.npp': 16, 'urn:nfc:sn:obex': 3}, cfg={'recv-lto': 1500, 'send-miu': 128, 'send-agf': False, 'send-lto': 1000, 'send-lsc': 3, 'recv-miu': 1024, 'recv-wks': 3, 'send-wks': 1}, _Thread__started=<_Event(_Verbose__verbose=False, _Event__flag=True, _Event__cond=<_Condition(_Verbose__verbose=False, _C...(truncated), throwflag=0) at ../Python/ceval.c:3836
---Type to continue, or q to quit---q
I haven't managed to reproduce it, it happens from time to time, but maybe this is all that is needed to find the bug. What I'm doing is using the NPP server to receive a message, which I do, and then use the npp client to send another message. What I think is happening is that the LLCP link goes down before I try to send the message...
Imported from Launchpad using lp2gh.