With a large CPS (~ 100) errors in the logs

[a72]

I get this error msg="TransactionLayer: Unhandled sip response. Possible retransmissions. Set UnhandledResponseHandler" caller=transactionLayer msg="response status=100 reason=Trying transport=UDP source=127.0.0.1:7322"

for UnhandledResponseHandler uses the function

func printResponse(r *sip.Response) {
	slog.Warn("☢️", "response", r)
}

time=2025-09-22T17:00:23.858 level=DEBUG caller=sip.go:45 msg="UDP write to 127.0.0.1:7312 -> 127.0.0.1:7322:\nINVITE sip:[email protected]:7322 SIP/2.0\r\nVia: SIP/2.0/UDP 127.0.0.1:7312;branch=z9hG4bK.6hkBZkpSlWArZXFM\r\nCall-ID: d9dd09b6-e452-4af7-881b-4c358b769b58\r\nCSeq: 1 INVITE\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=7EzbmJ\r\nTo: <sip:[email protected]>\r\nContact: <sip:[email protected]>\r\nContent-Length: 0\r\n\r\n"
time=2025-09-22T17:00:23.858 level=DEBUG caller=transaction_client_tx.go:75 msg="Client transaction initialized" caller=TransactionLayer tx=z9hG4bK.6hkBZkpSlWArZXFM__INVITE
time=2025-09-22T17:00:23.858 level=DEBUG caller=sip.go:35 msg="UDP read from 127.0.0.1:7312 <- 127.0.0.1:7322:\nSIP/2.0 100 Trying\r\nVia: SIP/2.0/UDP 127.0.0.1:7312;branch=z9hG4bK.6hkBZkpSlWArZXFM\r\nFrom: <sip:[email protected]>;tag=7EzbmJ\r\nTo: <sip:[email protected]>\r\nCall-ID: d9dd09b6-e452-4af7-881b-4c358b769b58\r\nCSeq: 1 INVITE\r\nContact: <sip:[email protected]>\r\nContent-Length: 0\r\n\r\n"
time=2025-09-22T17:00:23.858 level=DEBUG caller=sip.go:35 msg="UDP read from 127.0.0.1:7312 <- 127.0.0.1:7322:\nSIP/2.0 500 Outgoing call\r\nVia: SIP/2.0/UDP 127.0.0.1:7312;branch=z9hG4bK.6hkBZkpSlWArZXFM\r\nFrom: <sip:[email protected]>;tag=7EzbmJ\r\nTo: <sip:[email protected]>\r\nCall-ID: d9dd09b6-e452-4af7-881b-4c358b769b58\r\nCSeq: 1 INVITE\r\nContact: <sip:[email protected]>\r\nContent-Length: 0\r\n\r\n"
time=2025-09-22T17:00:23.858 level=DEBUG caller=sip.go:45 msg="UDP write to 127.0.0.1:7312 -> 127.0.0.1:7322:\nACK sip:[email protected]:7322 SIP/2.0\r\nVia: SIP/2.0/UDP 127.0.0.1:7312;branch=z9hG4bK.6hkBZkpSlWArZXFM\r\nMax-Forwards: 70\r\nFrom: <sip:[email protected]>;tag=7EzbmJ\r\nTo: <sip:[email protected]>\r\nCall-ID: d9dd09b6-e452-4af7-881b-4c358b769b58\r\nCSeq: 1 ACK\r\nContact: <sip:[email protected]>\r\nContent-Length: 0\r\n\r\n"
time=2025-09-22T17:00:23.859 level=DEBUG caller=transport_udp.go:367 msg="UDP reference decrement" src=127.0.0.1:7312 dst=127.0.0.1:7312 ref=2
time=2025-09-22T17:00:23.859 level=DEBUG caller=transaction_client_tx.go:257 msg="Client transaction destroyed" caller=TransactionLayer tx=z9hG4bK.6hkBZkpSlWArZXFM__INVITE
time=2025-09-22T17:00:23.859 level=WARN  caller=my_sip.go:31 msg=☢️ response="SIP/2.0 100 Trying\r\nVia: SIP/2.0/UDP 127.0.0.1:7312;branch=z9hG4bK.6hkBZkpSlWArZXFM\r\nFrom: <sip:[email protected]>;tag=7EzbmJ\r\nTo: <sip:[email protected]>\r\nCall-ID: d9dd09b6-e452-4af7-881b-4c358b769b58\r\nCSeq: 1 INVITE\r\nContact: <sip:[email protected]>\r\nContent-Length: 0\r\n\r\n"

According to the logs, after the ACK, it tries to process 100 Trying

I saw the same error when processing 500 messages.

[emiago]

Hi @a72 I think handling of dialog Write Ack could be here issue? I guess you use dialog as managment. Normally you can get that message if you got multiple same provisional responses?

I would not expect some races, but please confirm above for a start.

[a72]

I use the library to send messages to another service over the SIP protocol. Messaging is simple and of the same type.

INVITE ->
<- 100 Trying
<- 500 Outgoing
ACK ->

Speed of 100 CPS or more

to send, I use the construction tx, err := client.TransactionRequest(ctx, req)

The service does not send the same preliminary responses, I checked in pcap traces.

[emiago]

ok @a72 so maybe then only issue is that 500 is processed before 100. I thought something with ACK is issue. This is because responses are processed parallel. I am still not sure should this be a issue, as this can happen on network level. One improvement could be that, final responses should clear any provisional, but I left this yet open with Unhandled handler.

I will like to keep this open to think about. Thanks

[a72]

this cannot be a network problem, the exchange takes place on localhost.

[emiago]

Each response is handled as go routine. This was moved before transaction processing (previous versions had this after), but on other hand this actually gained performance on benchmarks. In real case scenario, there is no guarantee for order of received responses anyway.

So generally it should not affect SIP transaction processing (state is moved and finalized by non provisional), but yes it can create this strange logs when you stress it enough. Having this said, I would still like to keep open, to find can something here be improved.