Chronological Thread 

< Chronological >      < Thread >

---

Hi Andreas,

see my comments in-line.

Best regards
Michael

On Jun 29, 2005, at 11:27 Uhr, Andreas Fink wrote:

Hello,

I think we might have a race condition in SCTP lib.
I have my application crashing form time to time at startup but not always.
Here's what I do:

a) I create 4 threads. one thread for every M2PA link out of a MTP3 link

OK.

b) every of those threads opens an SCTP stream

I assume you mean SCTP associations.

c) usually only one of those SCTP streams can be established. This because the (development) configuration has 4 different IP's (my Laptop in the office, my laptop at home, my latop on VPN etc).

Usually everything works fine here but sometimes it crashes inside sctp_create/sctp_registerInstance

*You* have to make sure that only one thread uses the sctplib. Are you doing this?
The socketapilib, which uses the sctplib, uses multiple threads and also does the synchronisation.
You can look there how to do this.

Here's a log of my application with a backtrace and some explanation


2005-06-29 11:02:34 [2126] [10] DEBUG: MTP3 opening link [OPC:1-001-1][DPC:0-001-0][NI:0]
2005-06-29 11:02:34 [2126] [11] DEBUG: ILM_RX [MTP3:1:mtp3-cisco]->[M2PA:1:] [1005/1:MT_ADMIN_OPEN_REQ] [SESS:0] [LEN:0]:
2005-06-29 11:02:34 [2126] [12] DEBUG: ILM_RX [MTP3:1:mtp3-cisco]->[M2PA:2:] [1005/1:MT_ADMIN_OPEN_REQ] [SESS:0] [LEN:0]:
2005-06-29 11:02:34 [2126] [13] DEBUG: ILM_RX [MTP3:1:mtp3-cisco]->[M2PA:3:] [1005/1:MT_ADMIN_OPEN_REQ] [SESS:0] [LEN:0]:
2005-06-29 11:02:34 [2126] [14] DEBUG: ILM_RX [MTP3:1:mtp3-cisco]->[M2PA:4:] [1005/1:MT_ADMIN_OPEN_REQ] [SESS:0] [LEN:0]:

all 4 M2PA threads received a message from MTP3 layer tellling it to try to establish a connection.

2005-06-29 11:02:34 [2126] [11] DEBUG: SCTP[ERR] instance creation failed for [193.53.0.180:7701] -> [85.195.192.20:7701]
2005-06-29 11:02:34 [2126] [11] DEBUG: M2PA[1] sctp link creation failed for [193.53.0.180:7701] -> [85.195.192.20:7701]

instance 1 tells us its sctp_create failed. this is ok as thats not the active ip

2005-06-29 11:02:34 [2126] [12] DEBUG: SCTP[ERR] instance creation failed for [193.53.0.2:7702] -> [85.195.192.20:7702]
2005-06-29 11:02:34 [2126] [12] DEBUG: M2PA[2] sctp link creation failed for [193.53.0.2:7702] -> [85.195.192.20:7702]

instance 2 tells us its sctp_create failed. this is ok as thats not the active ip

2005-06-29 11:02:34 [2126] [14] DEBUG: SCTP[ERR] instance creation failed for [193.53.0.3:7704] -> [85.195.192.20:7704]
2005-06-29 11:02:34 [2126] [14] DEBUG: M2PA[4] sctp link creation failed for [193.53.0.3:7704] -> [85.195.192.20:7704]

instance 4 tells us its sctp_create failed. this is ok as thats not the active ip.
Interestingly instance 3 has not shown up yet.

2005-06-29 11:02:34 [2126] [10] DEBUG: ILM_RX [M2PA:1:]->[MTP3:1:mtp3-cisco] [1005/4:MT_ADMIN_OPEN_CONF] [SESS:0] [LEN:0]:
2005-06-29 11:02:34 [2126] [10] DEBUG: MTP3 opening link [OPC:1-001-1][DPC:0-001-0][NI:0][SLC:0] complete and FAIL
2005-06-29 11:02:34 [2126] [10] DEBUG: ILM_RX [M2PA:2:]->[MTP3:1:mtp3-cisco] [1005/4:MT_ADMIN_OPEN_CONF] [SESS:1] [LEN:0]:
2005-06-29 11:02:34 [2126] [10] DEBUG: MTP3 opening link [OPC:1-001-1][DPC:0-001-0][NI:0][SLC:1] complete and FAIL
2005-06-29 11:02:34 [2126] [10] DEBUG: ILM_RX [M2PA:4:]->[MTP3:1:mtp3-cisco] [1005/4:MT_ADMIN_OPEN_CONF] [SESS:3] [LEN:0]:
2005-06-29 11:02:34 [2126] [10] DEBUG: MTP3 opening link [OPC:1-001-1][DPC:0-001-0][NI:0][SLC:3] complete and FAIL

failure reports back to upper layer. meaning the threads have returned from sctp_lib.

Program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: KERN_PROTECTION_FAILURE at address: 0x00000000
[Switching to process 2126 thread 0x2d03]
0x0007fa30 in sctp_registerInstance (port=7703, noOfInStreams=2, noOfOutStreams=2, noOfLocalAddresses=1, localAddressList=0xf068c92c, ULPcallbackFunctions={dataArriveNotif = 0x3c0f8 <mm_sctp_dataArriveNotif>, sendFailureNotif = 0x3c30c <mm_sctp_sendFailureNotif>, networkStatusChangeNotif = 0x3c3d4 <mm_sctp_networkStatusChangeNotif>, communicationUpNotif = 0x3c5b4 <mm_sctp_communicationUpNotif>, communicationLostNotif = 0x3c6dc <mm_sctp_communicationLostNotif>, communicationErrorNotif = 0x3c7f0 <mm_sctp_communicationErrorNotif>, restartNotif = 0x3c904 <mm_sctp_restartNotif>, peerShutdownReceivedNotif = 0x3cadc <mm_sctp_peerShutdownReceivedNotif>, shutdownCompleteNotif = 0x3c9d4 <mm_sctp_shutdownCompleteNotif>, queueStatusChangeNotif = 0, asconfStatusNotif = 0}) at distribution.c:1831
1831 result = sctpInstance->sctpInstanceName;
(gdb) print result
$1 = 6
(gdb) print sctpInstance
$2 = (SCTP_instance *) 0x0
(gdb) backtrace
#0 0x0007fa30 in sctp_registerInstance (port=7703, noOfInStreams=2, noOfOutStreams=2, noOfLocalAddresses=1, localAddressList=0xf068c92c, ULPcallbackFunctions={dataArriveNotif = 0x3c0f8 <mm_sctp_dataArriveNotif>, sendFailureNotif = 0x3c30c <mm_sctp_sendFailureNotif>, networkStatusChangeNotif = 0x3c3d4 <mm_sctp_networkStatusChangeNotif>, communicationUpNotif = 0x3c5b4 <mm_sctp_communicationUpNotif>, communicationLostNotif = 0x3c6dc <mm_sctp_communicationLostNotif>, communicationErrorNotif = 0x3c7f0 <mm_sctp_communicationErrorNotif>, restartNotif = 0x3c904 <mm_sctp_restartNotif>, peerShutdownReceivedNotif = 0x3cadc <mm_sctp_peerShutdownReceivedNotif>, shutdownCompleteNotif = 0x3c9d4 <mm_sctp_shutdownCompleteNotif>, queueStatusChangeNotif = 0, asconfStatusNotif = 0}) at distribution.c:1831
#1 0x0003d03c in mm_sctp_create (srcip=0x615b28 "193.53.0.55", srcport=7703, dstip=0x615b58 "85.195.192.20", dstport=7703) at mm_sctp.c:367
#2 0x00040318 in prim_m2pa_admin_open_req (link=0x615ac0, ilm=0x6164b0) at mm_m2pa.c:911
#3 0x0003a064 in mm_layer_main (layer=0x615ac0) at mm_layers.c:661
#4 0x0005d768 in new_thread (arg=0x615ed0) at gwlib/gwthread-pthread.c:346
#5 0x9002c3d4 in _pthread_body ()


I looked at the code and thats what I see:

...
sctpInstance->default_maxBurst = DEFAULT_MAX_BURST;

InstanceList = g_list_insert_sorted(InstanceList, sctpInstance, &CompareInstanceNames);

result = sctpInstance->sctpInstanceName;

sctpInstance = old_Instance;
currentAssociation = old_assoc;
LEAVE_LIBRARY("sctp_registerInstance");
return result;
} /* end: sctp_registerInstance */

the strange thing is that on the line
sctpInstance->default_maxBurst = DEFAULT_MAX_BURST;
the variable sctpInstance must be non zero (otherwise it would have been crashing there already).
on the next line g_list_insert_sorted() is called passing on the pointer.
on the following line the code crashes because sctpInstance is zero. This is somewhat impossible unless someone writes over our current variable.

My (wild) guess is that thread #4 which failed clears its sctp instance variable and thread #3 uses the same one at the same time.
sctpInstance is defined as static variable in distribution.c.

in other words we must have a race condition.


Andreas Fink
Global Networks Schweiz AG

------------------------------------------------------------------
Tel: +41-61-6666330 Fax: +41-61-6666334 Mobile: +41-79-2457333
Global Networks Schweiz AG. Clarastrasse 3, 4058 Basel, Switzerland
Web: http://www.global-networks.ch/
afink AT global-networks.ch
------------------------------------------------------------------
ICQ: 101946485 MSN:
msn1 AT gni.ch
AIM: smsrelay Skype: andreasfink
Yahoo: finkconsulting SMS: +41792457333
PGP9: 0714 DF2B A189 A760 6201 5CBD D040 3E71 4DAF 68BB


_______________________________________________
discussion mailing list
discussion AT sctp.de
http://www.sctp.de/mailman/listinfo/discussion

---

• [SCTP-Discussion] Race condition in SCTP lib, Andreas Fink, 06/29/2005
  • Re: [SCTP-Discussion] Race condition in SCTP lib, Michael Tuexen, 06/29/2005
  • Re: [SCTP-Discussion] Race condition in SCTP lib, Thomas Dreibholz, 06/29/2005

---

Archive powered by MHonArc 2.6.19+.