Context Navigation

← Previous Ticket
Next Ticket →

#380 closed баг (fixed)

Гонки при доставке следующих за eCallEvent событий

Reported by:	alx	Owned by:	alx
Priority:	средний	Milestone:	1 очередь
Component:	any	Keywords:
Cc:

Description

При поступлении INVITE UAS создает объект CallData и привязывает его к вызову, затем генерирует широковещательное (ts == -1) событие eCallEvent. После обработки этого события канальным окончанием (если канальное окончание свободно и приняло решение обслужить вызов) вызов "привязывается" к конкретному окончанию установкой неотрицательного значения ts в CallData.

Может так случиться, что сразу вслед за INVITE приходят новые сообщения (например CANCEL), которые будут обработаны UAS (libeXosip2) до того как вызов будет "привязан" к конкретному окончанию. Созданные в результате события (eDisconnectEvent) тоже окажутся широковещательными (ts == -1). Но канальные окончания не рассчитаны на прием широковещательных eDisconnectEvent, поэтому такие события не будут обработаны, и канальное окончание останется в состоянии Connected.

Пример: имеем снятие вызова канального окончания FXO после "100 Trying":

04:45:59.689842 IP (tos 0x0, ttl 63, id 29456, offset 0, flags [+], proto UDP (17), length 1500)
    192.168.1.67.5060 > 192.168.0.135.5060: SIP, length: 1472
	INVITE sip:fxo@192.168.0.135 SIP/2.0
	Via: SIP/2.0/UDP 192.168.1.67:5060;branch=z9hG4bK-524287-1---30b25d5efc125300;rport
	Via: SIP/2.0/UDP 127.0.0.1:6060;rport=6060;branch=z9hG4bK905542527
	Max-Forwards: 69
	Record-Route: <sip:192.168.1.67:5060;transport=udp;lr>
	Contact: <sip:111@127.0.0.1:6060>
	To: <sip:fxo@192.168.0.135>
	From: "John West"<sip:111@192.168.1.67>;tag=655777206
	Call-ID: 141332225
	CSeq: 20 INVITE
	Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, REFER, NOTIFY, INFO, UPDATE, PRACK
	Content-Type: application/sdp
	Supported: replaces, timer, 100rel
	User-Agent: eXosip/5.2.1
	P-Asserted-Identity: "John West" <sip:111@192.168.1.67>
	X-Endpoint-Type: FXS
	Content-Length: 957
	
	v=0
	o=gateway 0 3 IN IP4 192.168.1.67
	s=conversation
	c=IN IP4 192.168.1.67
	t=0 0
	m=audio 10254 RTP/SAVP 8 0 4 18 101 98
	a=altc:1 IP6 2a03:1ac0:2e92:d910:ad:c3ff:fe00:6 10254
	a=altc:2 IP4 192.168.1.67 10254
	a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:t76pXJd0Z1ZY7UndIdHGpcCcou8Ddx+Mye8+uUEN
	a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:pMSYCnil/YborXX9bNvA3+jBeVuO1iU5pDcC6U+z
	a=rtpmap:8 PCMA/8000
	a=rtpmap:0 PCMU/8000
	a=rtpmap:4 G723/8000
	a=fmtp:4 annexa=no
	a=rtpmap:18 G729/8000
	a=fmtp:18 annexb=no
	a=rtpmap:101 telephone-event/8000
	a=fmtp:101 0-15
	a=rtpmap:98 PCMA/8000
	a=gpmd:98 vbd=yes
	m=audio 10254 RTP/AVP 8 0 4 18 101 98
	a=altc:1 IP6 2a03:1ac0:2e92:d910:ad:c3ff:fe00:6 10254
	a=altc:2 IP4 192.168.1.67 10254
	a=rtpmap:8 PCMA/8000
	a=rtpmap:0 PCMU/8000
	a
04:45:59.793955 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 348)
    192.168.0.135.5060 > 192.168.1.67.5060: SIP, length: 320
	SIP/2.0 100 Trying
	Via: SIP/2.0/UDP 192.168.1.67:5060;branch=z9hG4bK-524287-1---30b25d5efc125300;rport=5060
	Via: SIP/2.0/UDP 127.0.0.1:6060;rport=6060;branch=z9hG4bK905542527
	To: <sip:fxo@192.168.0.135>
	From: "John West"<sip:111@192.168.1.67>;tag=655777206
	Call-ID: 141332225
	CSeq: 20 INVITE
	Content-Length: 0
	
	
04:45:59.805828 IP (tos 0x0, ttl 63, id 0, offset 0, flags [DF], proto UDP (17), length 311)
    192.168.1.67.5060 > 192.168.0.135.5060: SIP, length: 283
	CANCEL sip:fxo@192.168.0.135 SIP/2.0
	Via: SIP/2.0/UDP 192.168.1.67:5060;branch=z9hG4bK-524287-1---30b25d5efc125300;rport
	Max-Forwards: 70
	To: <sip:fxo@192.168.0.135>
	From: "John West"<sip:111@192.168.1.67>;tag=655777206
	Call-ID: 141332225
	CSeq: 20 CANCEL
	Content-Length: 0
	
	
04:45:59.821022 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 311)
    192.168.0.135.5060 > 192.168.1.67.5060: SIP, length: 283
	SIP/2.0 200 OK
	Via: SIP/2.0/UDP 192.168.1.67:5060;branch=z9hG4bK-524287-1---30b25d5efc125300;rport=5060
	To: <sip:fxo@192.168.0.135>;tag=86c52c75
	From: "John West"<sip:111@192.168.1.67>;tag=655777206
	Call-ID: 141332225
	CSeq: 20 CANCEL
	Server: repro 1.12.0
	Content-Length: 0
	
	
04:45:59.866586 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 423)
    192.168.0.135.5060 > 192.168.1.67.5060: SIP, length: 395
	SIP/2.0 487 Request Terminated
	Via: SIP/2.0/UDP 192.168.1.67:5060;branch=z9hG4bK-524287-1---30b25d5efc125300;rport=5060
	Via: SIP/2.0/UDP 127.0.0.1:6060;rport=6060;branch=z9hG4bK905542527
	To: <sip:fxo@192.168.0.135>;tag=634931166
	From: "John West" <sip:111@192.168.1.67>;tag=655777206
	Call-ID: 141332225
	CSeq: 20 INVITE
	Server: repro 1.12.0
	User-Agent: eXosip/5.2.1
	Content-Length: 0
	
	
04:45:59.875832 IP (tos 0x0, ttl 63, id 0, offset 0, flags [DF], proto UDP (17), length 319)
    192.168.1.67.5060 > 192.168.0.135.5060: SIP, length: 291
	ACK sip:fxo@192.168.0.135 SIP/2.0
	Via: SIP/2.0/UDP 192.168.1.67:5060;branch=z9hG4bK-524287-1---30b25d5efc125300;rport
	Max-Forwards: 70
	To: <sip:fxo@192.168.0.135>;tag=634931166
	From: "John West"<sip:111@192.168.1.67>;tag=655777206
	Call-ID: 141332225
	CSeq: 20 ACK
	Content-Length: 0

В результате FXO осталось в состоянии Connected. Вот лог:

sip_ua[688]: repro.cpp:582: doSessionAccounting(): Session Created 'branch=z9hG4bK-524287-1---c392fc2efcccfd42'
sip_ua[688]: repro.cpp:757: doSessionAccounting(): Session Cancelled 'branch=z9hG4bK-524287-1---c392fc2efcccfd42'
sip_ua[654]: user_agent.cpp:2098: ---> transport 0: SIP event 2 (New call received!): cid=15, did=16, tid=16, rid=0, sid=0, nid=0
sip_ua[654]: user_agent.cpp:2225: INVITE received: sip:fxo@127.0.0.1:6060;transport=udp (Call-ID: 134475806@(null))
sip_ua[629]: ss7.cpp:1661: ---> SS7[2]: Incoming call, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[3]: Incoming call, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[4]: Incoming call, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[5]: Incoming call, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[6]: Incoming call, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[7]: Incoming call, ts=-1, flags=0001, data=15
sip_ua[629]: fxs.cpp:432: ---> ts=8, state=Idle: Incoming call, ts=-1, flags=0001, data=15
sip_ua[629]: fxo.cpp:343: ---> ts=9, state=Idle: Incoming call, ts=-1, flags=0001, data=15
sip_ua[654]: user_agent.cpp:2098: ---> transport 0: SIP event 13 (Call has been cancelled!): cid=15, did=16, tid=17, rid=0, sid=0, nid=0
sip_ua[654]: user_agent.cpp:2098: ---> transport 0: SIP event 21 (Bye Received!): cid=15, did=-1, tid=16, rid=0, sid=0, nid=0
sip_ua[629]: user_agent.cpp:4051: Call 15 routed to TS 9
sip_ua[629]: ss7.cpp:1661: ---> SS7[2]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[3]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[4]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[5]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[6]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[7]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: fxs.cpp:432: ---> ts=8, state=Idle: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: fxo.cpp:343: ---> ts=9, state=Connected: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[2]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[3]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[4]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[5]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[6]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[7]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: fxs.cpp:432: ---> ts=8, state=Idle: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: fxo.cpp:343: ---> ts=9, state=Connected: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[2]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[3]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[4]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[5]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[6]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[7]: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: fxs.cpp:432: ---> ts=8, state=Idle: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: fxo.cpp:343: ---> ts=9, state=Connected: Call disconnected, ts=-1, flags=0001, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[2]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[3]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[4]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[5]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[6]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: ss7.cpp:1661: ---> SS7[7]: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: fxs.cpp:432: ---> ts=8, state=Idle: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: fxo.cpp:343: ---> ts=9, state=Connected: Call disconnected, ts=-1, flags=0002, data=15
sip_ua[629]: fxo.cpp:343: ---> ts=9, state=Connected: CAS event, ts=9, flags=0000, data=5
sip_ua[629]: user_agent.cpp:4026: eXosip_call_build_answer(-1, 200) error -3
sip_ua[629]: user_agent.cpp:4032: ua_response_status(15, 200) error -2
sip_ua[629]: comcerto.cpp:6180: channel 9: answer

Здесь видно, что SIP event 13 (Call has been cancelled!) и SIP event 21 (Bye Received!) были обработаны до того как уже наше событие eCallEvent выло обработано канальным окончанием и вызов был "закреплен" за конкретным канальным окончанием. Как результат - два события eDisconnectEvent оказались широковещательными.

Варианты решения проблемы:

В CallData организовать отдельную очередь событий, и все следующие за eCallEvent события складывать в эту очередь, откладывая их доставку до момента, когда обработка eCallEvent будет закончена.

Механизм доставки событий оставить как есть, гл в каждом канальном окончании сделать обработку широковещательных событий eDisconnectEvent, которые матчить только по Call Id (event->data).

Следующие за INVITE собятия помещать в общую очередь, как это и происходит сейчас, но по окончании обработки eCallEvent, если вызов был прикреплен к канальному окончанию, модифицировать поле ts уже находящихся в очереди событий с таким же Call Id (event->data).

На первый взгляд, самым простым будет вариант 2.

Change History (1)

comment:1 by alx, 2 years ago

Resolution:	→ fixed
Status:	new → closed

In 1977/sip_ua:

Сделана обработка широковещательного события eDisconnectEvent. Closes #380.

Note: See TracTickets for help on using tickets.

Download in other formats: