Hello, I'm developing a softphone for android on top of PJSUA. Every time the client moves between Wifi/3G and receives new IP address I restart PJ. I noticed that sometimes when calling pjsua_destory it freezes on join on one of the worker threads (configured to 3). I added some logs and it seems that the following happens: 1. At some point during registration, the tcp transport is closed with error. 2. Thread X (see tid 6f2) below receives the callback, schedules a retry timer (60 sec ?), and continues below... 3. Thread Y (see tid 6f1 in bold) below receives timer callback for the same transaction, and tries to lock it but waits since it is already locked. 4. Thread X continues, and schedules destroy timer 5. Thread X executes destroy timer an destroys the transaction including its mutex. 5. Thread Y is waiting forever.... Later on when trying to join the worker threads, join on thread Y does not return. Can it be that one thread destroys the transaction that another thread tries to lock on, thus leading to thread freeze? How can it be solved ? Thanks, Yaron Note - the logs include my logs as well, some pj logs are suppressed. 03-17 02:00:28.825 D/libpjsip(17072): 02:00:28.827 tcpc0x571584 TCP connection closed 03-17 02:00:28.825 W/libpjsip(17072): 02:00:28.827 tsx0x56bf0c locking_tsx 1993 03-17 02:00:28.825 D/libpjsip(17072): 02:00:28.827 tsx0x56bf0c trying lock_tsx 47eafbf8 tid 6f2 03-17 02:00:28.825 D/libpjsip(17072): 02:00:28.827 tsx0x56bf0c after lock_tsx 47eafbf8 prev 0 tid 6f2 03-17 02:00:28.825 V/libpjsip(17072): 02:00:28.827 tsx0x56bf0c State changed from Calling to Terminated, event=TRANSPORT_ERROR 03-17 02:00:28.825 W/libpjsip(17072): 02:00:28.827 pjsua_acc.c SIP registration failed, status=503 (End of file (PJ_EEOF)) 03-17 02:00:28.825 V/libpjsip(17072): 02:00:28.827 sip_endpoint.c pjsip_endpt_cancel_timer(entry=0x817ca17c) 03-17 02:00:28.825 V/libpjsip(17072): 02:00:28.827 sip_endpoint.c pjsip_endpt_schedule_timer(entry=0x817ca17c, delay=60.0) *03-17 02:00:28.825 V/libpjsip(17072): 02:00:28.828 tsx0x56bf0c Timeout timer event* *03-17 02:00:28.825 D/libpjsip(17072): 02:00:28.828 sip_transactio tsx_timer_callback...before lock. self 4050f0/6f1 03-17 02:00:28.825 W/libpjsip(17072): 02:00:28.828 tsx0x56bf0c locking_tsx 1124 03-17 02:00:28.825 D/libpjsip(17072): 02:00:28.828 tsx0x56bf0c trying lock_tsx 47db5e4c tid 6f1* 03-17 02:00:28.830 V/libpjsip(17072): 02:00:28.836 atm0x581a84 Mutex destroyed by thread pjsua 03-17 02:00:28.830 V/libpjsip(17072): 02:00:28.836 regc0x5817f8 Mutex destroyed by thread pjsua 03-17 02:00:28.830 V/libpjsip(17072): 02:00:28.836 sip_endpoint.c Releasing pool regc0x5817f8 03-17 02:00:28.830 V/libpjsip(17072): 02:00:28.836 regc0x5817f8 destroy(): cap=3072, used=2284(74%), block0=0x57112c-0x571518 03-17 02:00:28.830 V/libpjsip(17072): 02:00:28.836 sip_endpoint.c pjsip_endpt_schedule_timer(entry=0x56c01c, delay=0.0) 03-17 02:00:28.830 W/libpjsip(17072): 02:00:28.836 tsx0x56bf0c unlocking_tsx 2006 03-17 02:00:28.830 D/libpjsip(17072): 02:00:28.836 tsx0x56bf0c before unlock_tsx 47eafbf8 prev 0 alive 1 tid 6f2 03-17 02:00:28.830 D/libpjsip(17072): 02:00:28.836 tsx0x56bf0c After unlock_tsx 47eafbf8 tid 6f2 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 sip_transport_ on_data_read...after tcp_init_shutdown...self 3601c0/6f2 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tsx0x56bf0c Timeout timer event 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 sip_transactio tsx_timer_callback...before lock. self 3601c0/6f2 03-17 02:00:28.835 W/libpjsip(17072): 02:00:28.837 tsx0x56bf0c locking_tsx 1124 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 tsx0x56bf0c trying lock_tsx 47eb5e4c tid 6f2 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 tsx0x56bf0c after lock_tsx 47eb5e4c prev 0 tid 6f2 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 sip_transactio tsx_timer_callback...before handler. self 3601c0/6f2 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tsx0x56bf0c State changed from Terminated to Destroyed, event=TIMER 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 hashtbl 0x4221e4: p_entry 0x56c160 deleted 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 sip_endpoint.c pjsip_endpt_schedule_timer(entry=0x57162c, delay=0.0) 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tdta0x4e0078 Destroying txdata Request msg REGISTER/cseq=54208 (tdta0x4e0078) 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 atm0x4e042c Mutex destroyed by thread pjsua 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 sip_endpoint.c Releasing pool tdta0x4e0078 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tdta0x4e0078 destroy(): cap=12096, used=6740(55%), block0=0x581f54-0x583e80 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tsx0x56bf0c Mutex destroyed by thread pjsua 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tsx0x56bf0c Mutex destroyed by thread pjsua 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tsx0x56bf0c Transaction destroyed! 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 sip_endpoint.c Releasing pool tsx0x56bf0c 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tsx0x56bf0c destroy(): cap=2048, used=800(39%), block0=0x56bf0c-0x56c6a8 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 sip_transactio tsx_timer_callback...after handler. self 3601c0/6f2 03-17 02:00:28.835 W/libpjsip(17072): 02:00:28.837 tsx0x56bf0c unlocking_tsx 1128 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 tsx0x56bf0c before unlock_tsx 47eb5e4c prev 0 alive 0 tid 6f2 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 tsx0x56bf0c After unlock_tsx 47eb5e4c tid 6f2 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 hashtbl 0x457c14: p_entry 0x572954 deleted 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 rtd0x20a300 destroy(): cap=4096, used=100(2%), block0=0x20a364-0x20b300 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tcp Mutex destroyed by thread pjsua 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 atm0x5728b8 Mutex destroyed by thread pjsua 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 tcpc0x571584 TCP transport destroyed with reason 70016: End of file (PJ_EEOF) 03-17 02:00:28.835 D/libpjsip(17072): 02:00:28.837 sip_transport_ tcp_destroy... self 3601c0/6f2 03-17 02:00:28.835 V/libpjsip(17072): 02:00:28.837 tcp destroy(): cap=6144, used=5676(92%), block0=0x44c0fc-0x44c2e8 -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.pjsip.org/pipermail/pjsip_lists.pjsip.org/attachments/20120318/e32152d8/attachment.html>
