Hi Benny, We are using the PJSIP 0.8.0 and have an issue with the TLS transport. After an un-SUBSCRIBE, the connection seems to be closed and the final NOTIFY from the other side is trying to do a fresh connection which fails. The log is attached. Please advice on it. Thanks, Manoj -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.pjsip.org/pipermail/pjsip_lists.pjsip.org/attachments/20081224/4b6d1830/attachment.html> -------------- next part -------------- 14:57:34.278 sip_endpoint.c Module "mod-invite" registered 14:57:34.278 sip_endpoint.c Module "mod-100rel" registered 14:57:34.278 sip_endpoint.c Module "mod-evsub" registered 14:57:34.278 sip_endpoint.c Module "mod-presence" registered 14:57:34.278 evsub.c Event pkg "presence" registered by mod-presence 14:57:34.278 sip_endpoint.c Module "mod-conference" registered 14:57:34.278 evsub.c Event pkg "conference" registered by mod-conference 14:57:34.278 sip_endpoint.c Module "mod-refer" registered 14:57:34.278 evsub.c Event pkg "refer" registered by mod-refer 14:57:34.278 sip_endpoint.c Module "mod_sipclient" registered 14:57:35.013 pasound.c PA message: Pa_GetDeviceInfo: Num input channels reported as 65535! Changed to 2. 14:57:35.013 pasound.c PA message: Pa_GetDeviceInfo: Num input channels reported as 65535! Changed to 2. 14:57:35.013 pasound.c PA message: Pa_GetDeviceInfo: Num output channels reported as 65535! Changed to 2. 14:57:36.169 pasound.c PortAudio sound library initialized, status=0 14:57:36.169 pasound.c PortAudio host api count=3 14:57:36.169 pasound.c Sound device count=10 14:57:36.169 pjlib select() I/O Queue created (028DB04C) 14:57:36.232 sip_inv.c Trying to register as sip:manoj at mydomain.com 14:57:36.232 endpoint Request msg REGISTER/cseq=18508 (tdta028F1F78) created. 14:57:36.232 tsx028F301C Transaction created for Request msg REGISTER/cseq=18509 (tdta028F1F78) 14:57:36.232 tsx028F301C Sending Request msg REGISTER/cseq=18509 (tdta028F1F78) in state Null 14:57:36.232 sip_resolve.c Target '10.2.0.53:443' type=TLS resolved to '10.2.0.53:443' type=TLS 14:57:36.232 tlsc028F484C TLS client transport created 14:57:36.232 tlsc028F484C TLS transport 10.2.0.64:21290 is connecting to 10.2.0.53:443... 14:57:36.232 tsx028F301C State changed from Null to Calling, event=TX_MSG 14:57:36.341 tlsc028F484C TCP transport 10.2.0.64:21290 is connected to 10.2.0.53:443 14:57:36.341 tlsc028F484C Starting SSL_connect() negotiation 14:57:37.857 tlsc028F484C SSL_connect() negotiation completes successfully 14:57:37.950 sip_endpoint.c Processing incoming message: Response msg 401/REGISTER/cseq=18509 (rdata028F4958) 14:57:37.950 tsx028F301C Incoming Response msg 401/REGISTER/cseq=18509 (rdata028F4958) in state Calling 14:57:37.950 tsx028F301C State changed from Calling to Completed, event=RX_MSG 14:57:37.950 tsx0290F3F4 Transaction created for Request msg REGISTER/cseq=18510 (tdta028F1F78) 14:57:37.950 tsx0290F3F4 Sending Request msg REGISTER/cseq=18510 (tdta028F1F78) in state Null 14:57:37.950 sip_resolve.c Target '10.2.0.53:443' type=TLS resolved to '10.2.0.53:443' type=TLS 14:57:37.950 tsx0290F3F4 State changed from Null to Calling, event=TX_MSG 14:57:38.060 sip_endpoint.c Processing incoming message: Response msg 200/REGISTER/cseq=18510 (rdata028F4958) 14:57:38.060 tsx0290F3F4 Incoming Response msg 200/REGISTER/cseq=18510 (rdata028F4958) in state Calling 14:57:38.060 tsx0290F3F4 State changed from Calling to Completed, event=RX_MSG 14:57:38.075 tsx0290F3F4 Timeout timer event 14:57:38.075 tsx0290F3F4 State changed from Completed to Terminated, event=TIMER 14:57:38.075 tsx0290F3F4 Timeout timer event 14:57:38.075 tsx0290F3F4 State changed from Terminated to Destroyed, event=TIMER 14:57:38.075 tsx0290F3F4 Transaction destroyed! 14:57:38.575 dlg0290F3F4 UAC dialog created 14:57:38.575 dlg0290F3F4 Module mod-invite added as dialog usage, data=02910140 14:57:38.575 dlg0290F3F4 Session count inc to 2 by mod-invite 14:57:38.575 dlg0290F3F4 Module mod-100rel added as dialog usage, data=02910C18 14:57:38.575 dlg0290F3F4 100rel module attached 14:57:38.575 inv0290F3F4 UAC invite session created for dialog dlg0290F3F4 14:57:38.575 endpoint Request msg INVITE/cseq=26501 (tdta02910F50) created. 14:57:38.575 inv0290F3F4 Sending Request msg INVITE/cseq=26501 (tdta02910F50) 14:57:38.575 dlg0290F3F4 Sending Request msg INVITE/cseq=26501 (tdta02910F50) 14:57:38.575 tsx02911FF4 Transaction created for Request msg INVITE/cseq=26500 (tdta02910F50) 14:57:38.575 tsx02911FF4 Sending Request msg INVITE/cseq=26500 (tdta02910F50) in state Null 14:57:38.575 sip_resolve.c Target '10.2.0.53:443' type=TLS resolved to '10.2.0.53:443' type=TLS 14:57:38.575 tsx02911FF4 State changed from Null to Calling, event=TX_MSG 14:57:38.575 dlg0290F3F4 Transaction tsx02911FF4 state changed to Calling 14:57:38.778 sip_endpoint.c Processing incoming message: Response msg 100/INVITE/cseq=26500 (rdata028F4958) 14:57:38.778 tsx02911FF4 Incoming Response msg 100/INVITE/cseq=26500 (rdata028F4958) in state Calling 14:57:38.778 tsx02911FF4 State changed from Calling to Proceeding, event=RX_MSG 14:57:38.778 dlg0290F3F4 Received Response msg 100/INVITE/cseq=26500 (rdata028F4958) 14:57:38.778 dlg0290F3F4 Transaction tsx02911FF4 state changed to Proceeding 14:57:43.044 tsx028F301C Timeout timer event 14:57:43.044 tsx028F301C State changed from Completed to Terminated, event=TIMER 14:57:43.044 tsx028F301C Timeout timer event 14:57:43.044 tsx028F301C State changed from Terminated to Destroyed, event=TIMER 14:57:43.044 tdta028F1F78 Destroying txdata Request msg REGISTER/cseq=18510 (tdta028F1F78) 14:57:43.044 tsx028F301C Transaction destroyed! 14:57:43.200 sip_endpoint.c Processing incoming message: Response msg 200/INVITE/cseq=26500 (rdata028F4958) 14:57:43.200 tsx02911FF4 Incoming Response msg 200/INVITE/cseq=26500 (rdata028F4958) in state Proceeding 14:57:43.200 tsx02911FF4 State changed from Proceeding to Terminated, event=RX_MSG 14:57:43.200 dlg0290F3F4 Received Response msg 200/INVITE/cseq=26500 (rdata028F4958) 14:57:43.200 dlg0290F3F4 Route-set updated 14:57:43.200 dlg0290F3F4 Route-set frozen 14:57:43.216 dlg0290F3F4 Transaction tsx02911FF4 state changed to Terminated 14:57:43.216 inv0290F3F4 Got SDP answer in Response msg 200/INVITE/cseq=26500 (rdata028F4958) 14:57:43.216 inv0290F3F4 SDP negotiation done, status=0 14:57:43.216 inv0290F3F4 Received Response msg 200/INVITE/cseq=26500 (rdata028F4958), sending ACK 14:57:43.216 endpoint Request msg ACK/cseq=26500 (tdta029013B0) created. 14:57:43.216 dlg0290F3F4 Sending Request msg ACK/cseq=26500 (tdta029013B0) 14:57:43.216 sip_resolve.c Target '10.2.0.53:443' type=TLS resolved to '10.2.0.53:443' type=TLS 14:57:43.310 tsx02911FF4 Timeout timer event 14:57:43.310 tsx02911FF4 State changed from Terminated to Destroyed, event=TIMER 14:57:43.310 tdta02910F50 Destroying txdata Request msg INVITE/cseq=26500 (tdta02910F50) 14:57:43.310 tsx02911FF4 Transaction destroyed! 14:57:43.810 dlg0428A7CC UAC dialog created 14:57:43.810 dlg0428A7CC Module mod-evsub added as dialog usage, data=02913DBC 14:57:43.810 evsub0428ADBC UAC subscription created, using dialog dlg0428A7CC 14:57:43.810 dlg0428A7CC Session count inc to 3 by mod-evsub 14:57:43.810 endpoint Request msg SUBSCRIBE/cseq=15725 (tdta029023F0) created. 14:57:43.810 dlg0428A7CC Sending Request msg SUBSCRIBE/cseq=15725 (tdta029023F0) 14:57:43.810 tsx0427D08C Transaction created for Request msg SUBSCRIBE/cseq=15724 (tdta029023F0) 14:57:43.810 tsx0427D08C Sending Request msg SUBSCRIBE/cseq=15724 (tdta029023F0) in state Null 14:57:43.810 sip_resolve.c Target '10.2.0.53:443' type=TLS resolved to '10.2.0.53:443' type=TLS 14:57:43.810 tsx0427D08C State changed from Null to Calling, event=TX_MSG 14:57:43.810 dlg0428A7CC Transaction tsx0427D08C state changed to Calling 14:57:43.810 evsub0428ADBC Subscription state changed NULL --> SENT 14:57:43.919 sip_endpoint.c Processing incoming message: Response msg 202/SUBSCRIBE/cseq=15724 (rdata028F4958) 14:57:43.919 tsx0427D08C Incoming Response msg 202/SUBSCRIBE/cseq=15724 (rdata028F4958) in state Calling 14:57:43.919 tsx0427D08C State changed from Calling to Completed, event=RX_MSG 14:57:43.919 dlg0428A7CC Received Response msg 202/SUBSCRIBE/cseq=15724 (rdata028F4958) 14:57:43.919 dlg0428A7CC Route-set updated 14:57:43.919 dlg0428A7CC Route-set frozen 14:57:43.919 dlg0428A7CC Transaction tsx0427D08C state changed to Completed 14:57:43.919 evsub0428ADBC Will refresh in 3595 seconds 14:57:43.919 evsub0428ADBC Timer UAC_REFRESH scheduled in 3595 seconds 14:57:43.919 evsub0428ADBC Subscription state changed SENT --> ACCEPTED 14:57:44.028 tsx0427D08C Timeout timer event 14:57:44.028 tsx0427D08C State changed from Completed to Terminated, event=TIMER 14:57:44.028 dlg0428A7CC Transaction tsx0427D08C state changed to Terminated 14:57:44.028 tsx0427D08C Timeout timer event 14:57:44.028 tsx0427D08C State changed from Terminated to Destroyed, event=TIMER 14:57:44.028 tdta029023F0 Destroying txdata Request msg SUBSCRIBE/cseq=15724 (tdta029023F0) 14:57:44.028 tsx0427D08C Transaction destroyed! 14:57:44.028 sip_endpoint.c Processing incoming message: Request msg NOTIFY/cseq=1 (rdata028F4958) 14:57:44.028 dlg0428A7CC Received Request msg NOTIFY/cseq=1 (rdata028F4958) 14:57:44.028 tsx0427D08C Transaction created for Request msg NOTIFY/cseq=1 (rdata028F4958) 14:57:44.028 tsx0427D08C Incoming Request msg NOTIFY/cseq=1 (rdata028F4958) in state Null 14:57:44.028 tsx0427D08C State changed from Null to Trying, event=RX_MSG 14:57:44.028 dlg0428A7CC Transaction tsx0427D08C state changed to Trying 14:57:44.028 evsub0428ADBC Will refresh in 3595 seconds 14:57:44.028 evsub0428ADBC Updating UAC_REFRESH timer 14:57:44.028 evsub0428ADBC Timer UAC_REFRESH scheduled in 3595 seconds 14:57:44.028 endpoint Response msg 200/NOTIFY/cseq=1 (tdta029023F0) created 14:57:44.028 dlg0428A7CC Sending Response msg 200/NOTIFY/cseq=1 (tdta029023F0) 14:57:44.028 tsx0427D08C Sending Response msg 200/NOTIFY/cseq=1 (tdta029023F0) in state Trying 14:57:44.028 tsx0427D08C State changed from Trying to Completed, event=TX_MSG 14:57:44.028 dlg0428A7CC Transaction tsx0427D08C state changed to Completed 14:57:44.028 evsub0428ADBC Subscription state changed ACCEPTED --> ACTIVE 14:57:44.122 tsx0427D08C Timeout timer event 14:57:44.122 tsx0427D08C State changed from Completed to Terminated, event=TIMER 14:57:44.122 dlg0428A7CC Transaction tsx0427D08C state changed to Terminated 14:57:44.122 tsx0427D08C Timeout timer event 14:57:44.122 tsx0427D08C State changed from Terminated to Destroyed, event=TIMER 14:57:44.122 tdta029023F0 Destroying txdata Response msg 200/NOTIFY/cseq=1 (tdta029023F0) 14:57:44.122 tsx0427D08C Transaction destroyed! 14:57:50.638 endpoint Request msg SUBSCRIBE/cseq=15726 (tdta029023F0) created. 14:57:50.638 dlg0428A7CC Sending Request msg SUBSCRIBE/cseq=15726 (tdta029023F0) 14:57:50.638 tsx042700CC Transaction created for Request msg SUBSCRIBE/cseq=15725 (tdta029023F0) 14:57:50.638 tsx042700CC Sending Request msg SUBSCRIBE/cseq=15725 (tdta029023F0) in state Null 14:57:50.638 sip_resolve.c Target '10.2.0.53:443' type=TLS resolved to '10.2.0.53:443' type=TLS 14:57:50.638 tsx042700CC State changed from Null to Calling, event=TX_MSG 14:57:50.638 dlg0428A7CC Transaction tsx042700CC state changed to Calling 14:57:50.653 endpoint Request msg BYE/cseq=26502 (tdta02903430) created. 14:57:50.653 dlg0290F3F4 Sending Request msg BYE/cseq=26502 (tdta02903430) 14:57:50.653 tsx0427D08C Transaction created for Request msg BYE/cseq=26501 (tdta02903430) 14:57:50.653 tsx0427D08C Sending Request msg BYE/cseq=26501 (tdta02903430) in state Null 14:57:50.653 sip_resolve.c Target '10.2.0.53:443' type=TLS resolved to '10.2.0.53:443' type=TLS 14:57:50.653 tsx0427D08C State changed from Null to Calling, event=TX_MSG 14:57:50.653 dlg0290F3F4 Transaction tsx0427D08C state changed to Calling 14:57:50.669 sip_endpoint.c Processing incoming message: Response msg 200/SUBSCRIBE/cseq=15725 (rdata028F4958) 14:57:50.669 tsx042700CC Incoming Response msg 200/SUBSCRIBE/cseq=15725 (rdata028F4958) in state Calling 14:57:50.669 tsx042700CC State changed from Calling to Completed, event=RX_MSG 14:57:50.669 dlg0428A7CC Received Response msg 200/SUBSCRIBE/cseq=15725 (rdata028F4958) 14:57:50.669 dlg0428A7CC Transaction tsx042700CC state changed to Completed 14:57:50.669 evsub0428ADBC Cancelling UAC_REFRESH timer 14:57:50.669 evsub0428ADBC Timer UAC_WAIT_NOTIFY scheduled in 5 seconds 14:57:50.669 endpoint Request msg REGISTER/cseq=18510 (tdta02904470) created. 14:57:50.669 tsx042A46CC Transaction created for Request msg REGISTER/cseq=18511 (tdta02904470) 14:57:50.669 tsx042A46CC Sending Request msg REGISTER/cseq=18511 (tdta02904470) in state Null 14:57:50.669 sip_resolve.c Target '10.2.0.53:443' type=TLS resolved to '10.2.0.53:443' type=TLS 14:57:50.669 tsx042A46CC State changed from Null to Calling, event=TX_MSG 14:57:50.778 tsx042700CC Timeout timer event 14:57:50.778 tsx042700CC State changed from Completed to Terminated, event=TIMER 14:57:50.778 dlg0428A7CC Transaction tsx042700CC state changed to Terminated 14:57:50.778 tsx042700CC Timeout timer event 14:57:50.778 tsx042700CC State changed from Terminated to Destroyed, event=TIMER 14:57:50.778 tdta029023F0 Destroying txdata Request msg SUBSCRIBE/cseq=15725 (tdta029023F0) 14:57:50.778 tsx042700CC Transaction destroyed! 14:57:50.778 tls028B311C TLS listener 10.2.0.64:21288: got incoming TCP connection from 10.2.0.53:2554, sock=4972 14:57:50.778 tlss042B1A1C TLS server transport created 14:57:50.778 tlss042B1A1C Starting SSL_accept() negotiation 14:57:50.872 tlss042B1A1C Error calling SSL_accept(): error:1408A0C1:SSL routines:SSL3_GET_CLIENT_HELLO:no shared cipher 14:57:50.872 tlss042B1A1C Error creating incoming TLS transport: Unknown TLS error (PJSIP_TLS_EUNKNOWN) 14:57:50.872 tlss042B1A1C TLS transport shutdown 14:57:54.450 sip_endpoint.c Processing incoming message: Response msg 200/BYE/cseq=26501 (rdata028F4958) 14:57:54.450 tsx0427D08C Incoming Response msg 200/BYE/cseq=26501 (rdata028F4958) in state Calling 14:57:54.450 tsx0427D08C State changed from Calling to Completed, event=RX_MSG 14:57:54.450 dlg0290F3F4 Received Response msg 200/BYE/cseq=26501 (rdata028F4958) 14:57:54.450 dlg0290F3F4 Transaction tsx0427D08C state changed to Completed 14:57:54.450 sip_inv.c Call DISCONNECTED [reason=200 (OK)] 14:57:54.450 sip_inv.c One call completed, application quitting... 14:57:54.450 tdta029013B0 Destroying txdata Request msg ACK/cseq=26500 (tdta029013B0) 14:57:54.450 dlg0290F3F4 Session count dec to 1 by mod-invite 14:57:54.544 tsx0427D08C Timeout timer event 14:57:54.544 tsx0427D08C State changed from Completed to Terminated, event=TIMER 14:57:54.544 dlg0290F3F4 Transaction tsx0427D08C state changed to Terminated 14:57:54.544 dlg0290F3F4 Dialog destroyed 14:57:54.544 tsx0427D08C Timeout timer event 14:57:54.544 tsx0427D08C State changed from Terminated to Destroyed, event=TIMER 14:57:54.544 tdta02903430 Destroying txdata Request msg BYE/cseq=26501 (tdta02903430) 14:57:54.544 tsx0427D08C Transaction destroyed! 14:57:54.560 sip_endpoint.c Processing incoming message: Response msg 200/REGISTER/cseq=18511 (rdata028F4958) 14:57:54.560 tsx042A46CC Incoming Response msg 200/REGISTER/cseq=18511 (rdata028F4958) in state Calling 14:57:54.560 tsx042A46CC State changed from Calling to Completed, event=RX_MSG
