OK, I just took 1.5 man days and did a backport of the mtxprof code, and did roughly the same set of tests on 1.4; I only ran the no-CDR tests, because, well, who cares about CDR's at this point. Here's a list of all the lock grants/held that exceeded 100k cpu ticks for the LOW load scenario in 1.4: (I'm removing all the locks done in other channel drivers) 42: [ 0] 1 0 129570 129570 UNLOCK:dnsmgr.c__do_reload__423__&refresh_lock 506: [ 0] 10 2 1393971 139397 chan_sip.c__sip_indicate__3922__&p->lock (chan_sip.c:4664:find_call:&p->lock[1]) 94: [ 0] 36 0 5034868 139857 UNLOCK:devicestate.c__do_devstate_changes__368__&(&state_changes)->lock 267: [ 0] 1 0 150748 150748 UNLOCK:chan_sip.c__sip_poke_all_peers__18066__&(&peerl)->_lock 514: [ 0] 2 0 321280 160640 UNLOCK:channel.c__ast_answer__1570__&chan->lock 55: [ 0] 1 0 167779 167779 UNLOCK:enum.c__ast_enum_init__664__&enumlock 508: [ 0] 10 0 1770918 177091 UNLOCK:channel.c__ast_indicate_data__2412__&chan->lock 7: [ 0] 187 0 33569122 179514 UNLOCK:logger.c__ast_verbose__902__&(&verbosers)->lock 377: [ 0] 1 0 200739 200739 UNLOCK:cdr_custom.c__load_config__101__&lock 131: [ 0] 2 0 562674 281337 UNLOCK:pbx.c__ast_add_hint__2214__&(&hints)->lock 37: [ 0] 1 0 307871 307871 UNLOCK:logger.c__ast_queue_log__365__&(&logchannels)->lock 40: [ 0] 2 0 641582 320791 UNLOCK:loader.c__load_modules__922__&(&module_list)->lock 513: [ 0] 2 0 716719 358359 UNLOCK:chan_sip.c__sip_answer__3718__&p->lock 538: [ 0] 4 0 1465317 366329 UNLOCK:channel.c__ast_hangup__1520__&chan->lock 478: [ 0] 2 0 753554 376777 UNLOCK:rtp.c__ast_rtp_make_compatible__1629__&src->lock 477: [ 0] 2 0 776338 388169 UNLOCK:rtp.c__ast_rtp_make_compatible__1628__&dest->lock 434: [ 0] 4 0 1738580 434645 UNLOCK:chan_sip.c__sip_new__4035__&i->lock 537: [ 0] 4 0 1814274 453568 UNLOCK:chan_sip.c__sip_hangup__3668__&p->lock 46: [ 0] 1 0 518941 518941 UNLOCK:manager.c__init_manager__3116__&(&users)->lock 449: [ 0] 12 0 7173971 597830 UNLOCK:chan_sip.c__sipsock_read__15663__&p->owner->lock 50: [ 0] 1 0 625821 625821 UNLOCK:cdr.c__do_reload__1449__&cdr_batch_lock 488: [ 0] 2 0 1348630 674315 UNLOCK:channel.c__ast_call__3082__&chan->lock 393: [ 0] 1 0 680851 680851 UNLOCK:func_odbc.c__odbc_load_module__569__&(&queries)->lock 277: [ 0] 3 0 2140435 713478 UNLOCK:chan_sip.c__restart_monitor__15944__&monlock 353: [ 0] 26 0 20898161 803775 UNLOCK:chan_sip.c__sipsock_read__15665__&p->lock 354: [ 0] 26 0 31370179 1206545 UNLOCK:chan_sip.c__sipsock_read__15666__&netlock 344: [ 0] 153 0 186221495 1217133 UNLOCK:chan_sip.c__do_monitor__15911__&monlock 441: [ 0] 2 0 2925509 1462754 pbx_start_time 322: [ 0] 20 0 34554460 1727723 UNLOCK:translate.c____ast_register_translator__767__&(&translators)->lock 116: [ 0] 1 0 2848199 2848199 UNLOCK:res_odbc.c__odbc_obj_connect__540__&obj->lock Here's a list of all the lock grants/held that exceeded 100k cpu ticks for the HIGH load scenario in 1.4: 488: [ 0] 755 0 79839820 105748 UNLOCK:channel.c__ast_queue_frame__962__&chan->lock (chan_sip.c:15616:sipsock_read:&chan->lock[1]) 391: [ 0] 757 0 82821248 109407 UNLOCK:chan_sip.c__do_monitor__15860__&iflock 465: [ 0] 755 0 84557002 111996 UNLOCK:channel.c__ast_answer__1570__&chan->lock 42: [ 0] 1 0 124824 124824 UNLOCK:dnsmgr.c__do_reload__423__&refresh_lock 385: [ 0] 1632 0 246673474 151147 UNLOCK:app_queue.c__device_state_thread__702__&device_state.lock 455: [ 0] 755 755 118518865 156978 channel.c__ast_answer__1545__&chan->lock (chan_sip.c:14116:handle_request_invite:&chan->lock[1]) 267: [ 0] 1 0 159716 159716 UNLOCK:chan_sip.c__sip_poke_all_peers__18066__&(&peerl)->_lock 7: [ 0] 187 0 30659277 163953 UNLOCK:logger.c__ast_verbose__902__&(&verbosers)->lock 55: [ 0] 1 0 170331 170331 UNLOCK:enum.c__ast_enum_init__664__&enumlock 360: [ 0] 1 0 177009 177009 UNLOCK:cdr_odbc.c__odbc_load_module__370__&odbc_lock 450: [ 0] 755 0 146315988 193796 pbx_start_time 354: [ 0] 1 0 194933 194933 UNLOCK:cdr_custom.c__load_config__101__&lock 215: [ 0] 1 0 205800 205800 UNLOCK:chan_sip.c__sip_register__4788__&(reg)->_lock 464: [ 0] 755 0 157546309 208670 UNLOCK:chan_sip.c__sip_answer__3718__&p->lock 338: [ 0] 2781 0 598643107 215261 UNLOCK:chan_sip.c__do_monitor__15911__&monlock 456: [ 0] 2265 0 539865999 238351 UNLOCK:chan_sip.c__sipsock_read__15663__&p->owner->lock 257: [ 0] 1 0 283248 283248 UNLOCK:chan_sip.c__reload_config__17566__&netlock 309: [ 0] 1 0 285117 285117 UNLOCK:app_followme.c__reload_followme__429__&(&followmes)->lock 131: [ 0] 2 0 592116 296058 UNLOCK:pbx.c__ast_add_hint__2214__&(&hints)->lock 471: [ 0] 1510 0 551307954 365104 UNLOCK:file.c__ast_filehelper__480__&(&formats)->lock 443: [ 0] 755 0 284054674 376231 UNLOCK:chan_sip.c__sip_new__4035__&i->lock 371: [ 0] 2275 0 856305920 376398 UNLOCK:chan_sip.c__sipsock_read__15665__&p->lock 46: [ 0] 1 0 522406 522406 UNLOCK:manager.c__init_manager__3116__&(&users)->lock 393: [ 0] 1 0 525189 525189 UNLOCK:func_odbc.c__odbc_load_module__569__&(&queries)->lock 50: [ 0] 1 0 609546 609546 UNLOCK:cdr.c__do_reload__1449__&cdr_batch_lock 372: [ 0] 2275 0 2015749323 886043 UNLOCK:chan_sip.c__sipsock_read__15666__&netlock 277: [ 0] 1 0 1309255 1309255 UNLOCK:chan_sip.c__restart_monitor__15944__&monlock 145: [ 0] 1 0 1705505 1705505 UNLOCK:chan_dahdi.c__setup_dahdi__11526__&iflock 324: [ 0] 20 0 34363351 1718167 UNLOCK:translate.c____ast_register_translator__767__&(&translators)->lock 116: [ 0] 1 0 2862121 2862121 UNLOCK:res_odbc.c__odbc_obj_connect__540__&obj->lock 171: [ 0] 1 0 3553473 3553473 UNLOCK:chan_iax2.c__reload_firmware__2060__&waresl.lock 305: [ 0] 4 0 50094145 12523536 UNLOCK:db.c__ast_db_put__166__&dblock This isn't promising to be an easy sort of analysis. Let's try this: low-load - high-load time comparisons in 1.4; I combined and sorted the low and high load profiles, and then looked at the pairs to see if anything sticks out. 540: [ 0] 4 0 1806 451 autoservice.c__ast_autoservice_stop__257__&(&aslist)->lock 482: [ 0] 836 0 603536 721 autoservice.c__ast_autoservice_stop__257__&(&aslist)->lock 356: [ 0] 3 0 2941 980 cdr.c__ast_cdr_register__120__&(&be_list)->lock 379: [ 0] 3 0 3675 1225 cdr.c__ast_cdr_register__120__&(&be_list)->lock 519: [ 0] 2 0 304 152 channel.c__ast_answer__1556__&chan->lock 443: [ 0] 836 836 115142497 137730 channel.c__ast_answer__1556__&chan->lock (chan_sip.c:14116:handle_request_invite:&chan->lock[1]) 501: [ 0] 586 4 196591 335 channel.c____ast_read__1993__&chan->lock (chan_sip.c:15616:sipsock_read:&chan->lock[1]) 470: [ 0] 5851 835 3430067 586 channel.c____ast_read__1993__&chan->lock (chan_sip.c:15616:sipsock_read:&chan->lock[2]) 496: [ 0] 1172 3 1095149 934 channel.c__ast_waitfor_nandfds__1696__&c[x]->lock (chan_sip.c:15616:sipsock_read:&c[x]->lock[1]) 467: [ 0] 5851 835 86415824 14769 channel.c__ast_waitfor_nandfds__1696__&c[x]->lock (chan_sip.c:15616:sipsock_read:&c[x]->lock[1]) 288: [ 10] 3 0 9340 3113 channel_find_locked 288: [ 10] 5 0 12253 2450 channel_find_locked 275: [ 0] 151 0 25610 169 chan_sip.c__do_monitor__15786__&iflock 275: [ 0] 3959 0 1068395 269 chan_sip.c__do_monitor__15786__&iflock 326: [ 0] 144 0 105516 732 chan_sip.c__do_monitor__15879__&monlock 324: [ 0] 3118 0 1161291 372 chan_sip.c__do_monitor__15879__&monlock 369: [ 0] 28 0 15339 547 chan_sip.c__find_call__4632__&iflock 347: [ 0] 2516 0 985136 391 chan_sip.c__find_call__4632__&iflock 443: [ 0] 2 0 493 246 chan_sip.c__handle_request_invite__14116__&c->lock 437: [ 0] 836 0 452384 541 chan_sip.c__handle_request_invite__14116__&c->lock 501: [ 0] 1 0 168 168 chan_sip.c__sip_destroy__3341__&iflock 513: [ 0] 5 0 2373 474 chan_sip.c__sip_destroy__3341__&iflock 544: [ 0] 4 1 19057 4764 chan_sip.c__sip_hangup__3553__&p->lock (chan_sip.c:4664:find_call:&p->lock[1]) 486: [ 0] 836 835 17921474 21437 chan_sip.c__sip_hangup__3553__&p->lock (chan_sip.c:4664:find_call:&p->lock[1]) 436: [ 0] 1750 0 583772 333 ext_match 430: [ 0] 15048 0 13951719 927 ext_match 444: [ 0] 2 0 2923567 1461783 pbx_start_time 438: [ 0] 836 0 175029516 209365 pbx_start_time 386: [ 0] 38 0 3715941 97787 UNLOCK:app_queue.c__device_state_thread__702__&device_state.lock 364: [ 0] 1598 0 265821996 166346 UNLOCK:app_queue.c__device_state_thread__702__&device_state.lock 385: [ 0] 38 0 320756 8440 UNLOCK:app_queue.c__statechange_queue__739__&device_state.lock 361: [ 0] 1598 0 17882439 11190 UNLOCK:app_queue.c__statechange_queue__739__&device_state.lock 534: [ 0] 572 0 15557309 27198 UNLOCK:channel.c__ast_write__2809__&chan->lock 466: [ 0] 5016 0 250526037 49945 UNLOCK:channel.c__ast_write__2809__&chan->lock 392: [ 0] 6 0 488522 81420 UNLOCK:chan_sip.c__do_monitor__15860__&iflock 372: [ 0] 840 0 105474700 125565 UNLOCK:chan_sip.c__do_monitor__15860__&iflock 276: [ 0] 145 0 1640568 11314 UNLOCK:chan_sip.c__do_monitor__15866__&iflock 276: [ 0] 3119 0 81347319 26081 UNLOCK:chan_sip.c__do_monitor__15866__&iflock 499: [ 0] 3 0 41464 13821 UNLOCK:chan_sip.c__retrans_pkt__2021__&pkt->owner->lock 405: [ 0] 21 0 1044864 49755 UNLOCK:chan_sip.c__retrans_pkt__1950__&pkt->owner->lock 533: [ 0] 572 0 13116650 22931 UNLOCK:chan_sip.c__sip_write__3756__&p->lock 465: [ 0] 5016 0 216000275 43062 UNLOCK:chan_sip.c__sip_write__3756__&p->lock The above show locks that get slower/held longer as load increases. Now, for a 1.4 to trunk comparison: Note that 1.4 runs involved 836 high-speed-overlapped-10-deep calls, whereas trunk involved 1166 such calls. 365: [ 0] 1598 0 416166 260 app_queue.c__handle_statechange__645__&(&interfaces)->lock 210: [ 0] 6998 0 7165334 1023 app_queue.c__handle_statechange__768__&(&interfaces)->lock 156: 4[ 0] 23 0 5378 233 astobj2.c__ao2_lock__140__&p->priv_data.lock 16: [ 0] 34001 2333 846771759 24904 astobj2.c__ao2_lock__154__&p->priv_data.lock (astobj2.c:154:ao2_lock:&p->priv_data.lock[1]) 482: 4[ 0] 836 0 603536 721 autoservice.c__ast_autoservice_stop__257__&(&aslist)->lock 254: [ 0] 1166 0 1549165 1328 autoservice.c__ast_autoservice_stop__251__&(&aslist)->lock 226: 4[ 0] 1599 0 700861 438 chan_agent.c__agent_devicestate_cb__294__&(&agents)->lock 185: [ 0] 6999 0 3956506 565 chan_agent.c__agent_devicestate_cb__277__&(&agents)->lock 443: 4[ 0] 836 836 115142497 137730 channel.c__ast_answer__1556__&chan->lock (chan_sip.c:14116:handle_request_invite:&chan->lock[1]) 226: [ 0] 1166 0 733110 628 channel.c____ast_answer__1715__&chan->lock_dont_use 492: 4[ 0] 836 0 138874 166 channel.c__ast_channel_free__1254__&chan->lock 261: [ 0] 1166 0 651680 558 channel.c__ast_channel_free__1327__&chan->lock_dont_use 490: 4[ 0] 836 0 138815 166 channel.c__ast_channel_free__1244__&chan->lock 259: [ 0] 1166 0 682490 585 channel.c__ast_channel_free__1317__&chan->lock_dont_use 481: 4[ 0] 836 0 209006 250 channel.c__ast_hangup__1469__&chan->lock 253: [ 0] 1166 0 1324815 1136 channel.c__ast_hangup__1614__&chan->lock_dont_use 474: 4[ 0] 1672 0 489859 292 channel.c__ast_queue_frame__923__&chan->lock 246: [ 0] 2332 0 1262973 541 channel.c__ast_queue_frame__971__&chan->lock_dont_use 472: 4[ 0] 836 0 215049 257 channel.c__ast_queue_hangup__972__&chan->lock 244: [ 0] 1166 0 565486 484 channel.c__ast_queue_hangup__1017__&chan->lock_dont_use 470: 4[ 0] 5851 835 3430067 586 channel.c____ast_read__1993__&chan->lock (chan_sip.c:15616:sipsock_read:&chan->lock[2]) 242: [ 0] 6993 1166 4190081 599 channel.c____ast_read__2401__&chan->lock_dont_use (chan_sip.c:18893:handle_request_do:&chan->lock_dont_use[2]) 475: 4[ 0] 9185 9185 7144593 777 channel.c____ast_read__1999__&chan->lock (chan_sip.c:15616:sipsock_read:&chan->lock[1]) 247: [ 0] 0 12826 0 0 channel.c____ast_read__2407__&chan->lock_dont_use (chan_sip.c:18893:handle_request_do:&chan->lock_dont_use[1]) 478: 4[ 0] 836 0 200980 240 channel.c__ast_softhangup__1444__&chan->lock 250: [ 0] 1166 0 688680 590 channel.c__ast_softhangup__1588__&chan->lock_dont_use 467: 4[ 0] 5851 835 86415824 14769 channel.c__ast_waitfor_nandfds__1696__&c[x]->lock (chan_sip.c:15616:sipsock_read:&c[x]->lock[1]) 238: [ 0] 8159 1166 215304508 26388 channel.c__ast_waitfor_nandfds__1888__&c[x]->lock_dont_use (chan_sip.c:18893:handle_request_do:&c[x]->lock_dont_use[1]) 462: 4[ 0] 5016 0 1374715 274 channel.c__ast_write__2631__&chan->lock 236: [ 0] 6993 0 4895889 700 channel.c__ast_write__3040__&chan->lock_dont_use 289: 4[ 0] 3 0 1208 402 channel.c__channel_find_locked__1065__&(&channels)->lock 224: [ 0] 3496 1953 2057525 588 channel.c__channel_find_locked__1170__&c->lock_dont_use (channel.c:1715:__ast_answer:&c->lock_dont_use[1]) 460: 4[ 0] 1672 0 710828 425 channel.c__set_format__2840__&chan->lock 234: [ 0] 2332 0 4266936 1829 channel.c__set_format__3259__&chan->lock_dont_use 288: 4[ 10] 3 0 9340 3113 channel_find_locked 207: [ 10] 6998 0 132950023 18998 channel_find_locked 324: 4[ 0] 3118 0 1161291 372 chan_sip.c__do_monitor__15879__&monlock 139: [ 0] 3544 0 2371032 669 chan_sip.c__do_monitor__19310__&monlock 76: 4[ 0] 4130 0 1111746 269 config.c__find_engine__1307__&config_lock 29: [ 0] 24629 0 15138360 614 config.c__find_engine__1942__&config_lock 92: 4[ 0] 5022 0 1210501 241 devicestate.c____ast_device_state_changed_literal__315__&(&state_changes)->lock 153: [ 0] 7000 0 4185547 597 devicestate.c____ast_devstate_changed_literal__479__&(&state_changes)->lock 101: 4[ 0] 1600 0 327564 204 devicestate.c__do_devstate_changes__371__&(&state_changes)->lock 45: [ 0] 5799 0 3495025 602 devicestate.c__do_devstate_changes__550__&(&state_changes)->lock 456: 4[ 0] 2508 0 1070852 426 file.c__ast_stopstream__143__&tmp->lock 232: [ 0] 3498 0 2335668 667 file.c__ast_stopstream__123__&tmp->lock_dont_use 68: 4[ 0] 4367 0 2307748 528 loader.c__ast_update_use_count__933__&(&updaters)->lock 61: [ 0] 6047 0 6701267 1108 loader.c__ast_update_use_count__967__&(&updaters)->lock 454: 4[ 0] 836 0 254614 304 pbx.c__ast_explicit_goto__4595__&chan->lock 230: [ 0] 1166 0 720664 618 pbx.c__ast_explicit_goto__6528__&chan->lock_dont_use 497: 4[ 0] 836 0 290075 346 pbx.c__decrease_call_count__2595__&maxcalllock 263: [ 0] 1166 0 669809 574 pbx.c__decrease_call_count__3943__&maxcalllock 439: 4[ 0] 836 0 201092 240 pbx.c__increase_call_count__2572__&maxcalllock 222: [ 0] 1166 0 710353 609 pbx.c__increase_call_count__3903__&maxcalllock 446: 4[ 0] 1672 0 546611 326 pbx.c__pbx_builtin_getvar_helper__5810__&chan->lock 227: [ 0] 2332 0 1890889 810 pbx.c__pbx_builtin_getvar_helper__8065__&chan->lock_dont_use 435: 4[ 0] 3344 0 1012704 302 pbx.c__pbx_builtin_setvar_helper__5890__&chan->lock 219: [ 0] 9328 0 5824638 624 pbx.c__pbx_builtin_setvar_helper__8142__&chan->lock_dont_use 438: 4[ 0] 836 0 175029516 209365 pbx_start_time 221: [ 0] 1166 0 436479743 374339 pbx_start_time 252: 4[ 0] 1702 1 828721 486 sched.c__ast_sched_add_variable__223__&con->lock (sched.c:154:ast_sched_wait:&con->lock[1]) 103: [ 0] 2370 1 4033386 1701 sched.c__ast_sched_add_variable__284__&con->lock (sched.c:174:ast_sched_wait:&con->lock[1]) 260: 4[ 0] 1686 0 444992 263 sched.c__ast_sched_del__268__&con->lock 107: [ 0] 2350 0 3675709 1564 sched.c__ast_sched_del__343__&con->lock 325: 4[ 0] 8285 0 2745807 331 sched.c__ast_sched_runq__340__&con->lock 140: [ 0] 10678 0 7759167 726 sched.c__ast_sched_runq__459__&con->lock 163: 4[ 0] 9126 0 1891118 207 sched.c__ast_sched_wait__154__&con->lock 85: [ 0] 11849 0 6851731 578 sched.c__ast_sched_wait__174__&con->lock 484: 4[ 0] 836 0 182086 217 sched.c__sched_context_destroy__92__&con->lock 256: [ 0] 1166 0 646363 554 sched.c__sched_context_destroy__109__&con->lock 30: 4[ 0] 217 0 104148 479 stdtime/localtime.c__ast_tzset__1024__&(&zonelist)->lock 23: [ 0] 2247 0 1602255 713 stdtime/localtime.c__ast_tzset__1018__&(&zonelist)->lock 366: 4[ 0] 1598 0 2451315 1533 UNLOCK:app_queue.c__handle_statechange__657__&(&interfaces)->lock 211: [ 0] 6998 0 26184273 3741 UNLOCK:app_queue.c__handle_statechange__780__&(&interfaces)->lock 157: 4[ 0] 23 0 81093 3525 UNLOCK:astobj2.c__ao2_unlock__156__&p->priv_data.lock 17: [ 0] 74410 0 6161782 82 UNLOCK:astobj2.c__ao2_unlock__170__&p->priv_data.lock 483: 4[ 0] 836 0 2335474 2793 UNLOCK:autoservice.c__ast_autoservice_stop__283__&(&aslist)->lock 255: [ 0] 1166 0 8186881 7021 UNLOCK:autoservice.c__ast_autoservice_stop__277__&(&aslist)->lock 227: 4[ 0] 1599 0 2849965 1782 UNLOCK:chan_agent.c__agent_devicestate_cb__317__&(&agents)->lock 186: [ 0] 6999 0 44988052 6427 UNLOCK:chan_agent.c__agent_devicestate_cb__308__&(&agents)->lock 453: 4[ 0] 836 0 105325526 125987 UNLOCK:channel.c__ast_answer__1581__&chan->lock 229: [ 0] 1166 0 447221871 383552 UNLOCK:channel.c____ast_answer__1754__&chan->lock_dont_use 491: 4[ 0] 836 0 1064321 1273 UNLOCK:channel.c__ast_channel_free__1245__&chan->lock 260: [ 0] 1166 0 2739690 2349 UNLOCK:channel.c__ast_channel_free__1318__&chan->lock_dont_use 493: 4[ 0] 836 0 1057700 1265 UNLOCK:channel.c__ast_channel_free__1255__&chan->lock 262: [ 0] 1166 0 2653034 2275 UNLOCK:channel.c__ast_channel_free__1328__&chan->lock_dont_use 488: 4[ 0] 836 0 47356005 56645 UNLOCK:channel.c__ast_hangup__1531__&chan->lock 258: [ 0] 1166 0 270635275 232105 UNLOCK:channel.c__ast_hangup__1675__&chan->lock_dont_use 479: 4[ 0] 836 0 1916508 2292 UNLOCK:channel.c__ast_queue_frame__928__&chan->lock (channel.c:1444:ast_softhangup:&chan->lock[1]) 251: [ 0] 1166 0 3976740 3410 UNLOCK:channel.c__ast_queue_frame__976__&chan->lock_dont_use (channel.c:1588:ast_softhangup:&chan->lock_dont_use[1]) 476: 4[ 0] 836 0 78518879 93922 UNLOCK:channel.c__ast_queue_frame__962__&chan->lock (chan_sip.c:15616:sipsock_read:&chan->lock[1]) 248: [ 0] 1166 0 875115204 750527 UNLOCK:channel.c__ast_queue_frame__1007__&chan->lock_dont_use (chan_sip.c:18893:handle_request_do:&chan->lock_dont_use[1]) 473: 4[ 0] 836 0 997717 1193 UNLOCK:channel.c__ast_queue_hangup__975__&chan->lock (chan_sip.c:15616:sipsock_read:&chan->lock[1]) 245: [ 0] 1166 0 5263310 4513 UNLOCK:channel.c__ast_queue_hangup__1020__&chan->lock_dont_use (chan_sip.c:18893:handle_request_do:&chan->lock_dont_use[1]) 471: 4[ 0] 4180 0 31014555 7419 UNLOCK:channel.c____ast_read__2081__&chan->lock 243: [ 0] 5827 0 397319514 68185 UNLOCK:channel.c____ast_read__2480__&chan->lock_dont_use 477: 4[ 0] 836 0 1724307 2062 UNLOCK:channel.c____ast_read__2384__&chan->lock 249: [ 0] 1166 0 3565492 3057 UNLOCK:channel.c____ast_read__2797__&chan->lock_dont_use 480: 4[ 0] 836 0 3121141 3733 UNLOCK:channel.c__ast_softhangup__1446__&chan->lock 252: [ 0] 1166 0 7623261 6537 UNLOCK:channel.c__ast_softhangup__1590__&chan->lock_dont_use 468: 4[ 0] 5851 0 8512848 1454 UNLOCK:channel.c__ast_waitfor_nandfds__1718__&c[x]->lock 239: [ 0] 8159 0 24178302 2963 UNLOCK:channel.c__ast_waitfor_nandfds__1908__&c[x]->lock_dont_use 466: 4[ 0] 5016 0 250526037 49945 UNLOCK:channel.c__ast_write__2809__&chan->lock 237: [ 0] 6993 0 980913380 140270 UNLOCK:channel.c__ast_write__3224__&chan->lock_dont_use 290: 4[ 0] 3 0 70582 23527 UNLOCK:channel.c__channel_find_locked__1128__&(&channels)->lock 461: 4[ 0] 1672 0 3872007 2315 UNLOCK:channel.c__set_format__2844__&chan->lock (file.c:143:ast_stopstream:&chan->lock[1]) 235: [ 0] 2332 0 16521009 7084 UNLOCK:channel.c__set_format__3263__&chan->lock_dont_use (file.c:123:ast_stopstream:&chan->lock_dont_use[1]) 274: 4[ 0] 3119 0 4127647 1323 UNLOCK:chan_sip.c__do_monitor__15767__&sip_reload_lock 117: [ 0] 3545 0 9061319 2556 UNLOCK:chan_sip.c__do_monitor__19273__&sip_reload_lock 345: 4[ 0] 3118 0 177693282 56989 UNLOCK:chan_sip.c__do_monitor__15911__&monlock 142: [ 0] 3544 0 158495444 44722 UNLOCK:chan_sip.c__do_monitor__19316__&monlock 213: 4[ 0] 1 0 28234 28234 UNLOCK:chan_sip.c__sip_register__4787__&(®l)->_lock 100: [ 0] 1 0 48615 48615 UNLOCK:chan_sip.c__sip_register__6353__&(®l)->_lock 212: 4[ 0] 1 0 9167 9167 UNLOCK:chan_sip.c__sip_register__4787__&(reg)->_lock 99: [ 0] 1 0 9796 9796 UNLOCK:chan_sip.c__sip_register__6353__&(reg)->_lock 77: 4[ 0] 4130 0 7900039 1912 UNLOCK:config.c__find_engine__1327__&config_lock 30: [ 0] 24629 0 73227872 2973 UNLOCK:config.c__find_engine__1962__&config_lock 93: 4[ 0] 5022 0 9364220 1864 UNLOCK:devicestate.c____ast_device_state_changed_literal__320__&(&state_changes)->lock 154: [ 0] 7000 0 142140455 20305 UNLOCK:devicestate.c____ast_devstate_changed_literal__482__&(&state_changes)->lock 94: 4[ 0] 1601 0 5448403 3403 UNLOCK:devicestate.c__do_devstate_changes__368__&(&state_changes)->lock 156: [ 0] 5798 0 -1924242335 -331880 UNLOCK:devicestate.c__do_devstate_changes__555__&(&state_changes)->lock 457: 4[ 0] 2508 0 6417297 2558 UNLOCK:file.c__ast_stopstream__158__&tmp->lock 233: [ 0] 3498 0 19378366 5539 UNLOCK:file.c__ast_stopstream__138__&tmp->lock_dont_use 69: 4[ 0] 4367 0 8982276 2056 UNLOCK:loader.c__ast_update_use_count__936__&(&updaters)->lock 62: [ 0] 6047 0 44150339 7301 UNLOCK:loader.c__ast_update_use_count__970__&(&updaters)->lock 455: 4[ 0] 836 0 2100795 2512 UNLOCK:pbx.c__ast_explicit_goto__4608__&chan->lock 231: [ 0] 1166 0 4379875 3756 UNLOCK:pbx.c__ast_explicit_goto__6541__&chan->lock_dont_use 449: 4[ 0] 1672 0 14216225 8502 UNLOCK:pbx.c__pbx_builtin_getvar_helper__5834__&chan->lock (channel.c:1556:ast_answer:&chan->lock[1]) 228: [ 0] 2332 0 118104135 50644 UNLOCK:pbx.c__pbx_builtin_getvar_helper__8087__&chan->lock_dont_use (channel.c:1715:__ast_answer:&chan->lock_dont_use[1]) 436: 4[ 0] 3344 0 20297611 6069 UNLOCK:pbx.c__pbx_builtin_setvar_helper__5921__&chan->lock (chan_sip.c:15616:sipsock_read:&chan->lock[1]) 220: [ 0] 9328 0 86767696 9301 UNLOCK:pbx.c__pbx_builtin_setvar_helper__8180__&chan->lock_dont_use 253: 4[ 0] 1702 0 12839692 7543 UNLOCK:sched.c__ast_sched_add_variable__243__&con->lock 104: [ 0] 2370 0 188353702 79474 UNLOCK:sched.c__ast_sched_add_variable__304__&con->lock 261: 4[ 0] 1686 0 3548518 2104 UNLOCK:sched.c__ast_sched_del__284__&con->lock 108: [ 0] 2350 0 215438620 91676 UNLOCK:sched.c__ast_sched_del__372__&con->lock 336: 4[ 0] 8285 0 23817725 2874 UNLOCK:sched.c__ast_sched_runq__383__&con->lock 141: [ 0] 10678 0 46116672 4318 UNLOCK:sched.c__ast_sched_runq__505__&con->lock 164: 4[ 0] 9126 0 18546713 2032 UNLOCK:sched.c__ast_sched_wait__162__&con->lock 86: [ 0] 11849 0 41564732 3507 UNLOCK:sched.c__ast_sched_wait__182__&con->lock 485: 4[ 0] 836 0 1544261 1847 UNLOCK:sched.c__sched_context_destroy__105__&con->lock 257: [ 0] 1166 0 41790476 35840 UNLOCK:sched.c__sched_context_destroy__125__&con->lock 49: [ 0] 21002 0 183457278 8735 UNLOCK:taskprocessor.c__ast_taskprocessor_push__499__&tps->taskprocessor_lock 50: [ 0] 21002 0 1446474999 68873 UNLOCK:taskprocessor.c__tps_processing_function__300__&i->taskprocessor_lock 56: [ 0] 21002 0 51424680 2448 UNLOCK:taskprocessor.c__tps_processing_function__320__&i->taskprocessor_lock 52: [ 0] 21002 0 51347302 2444 UNLOCK:taskprocessor.c__tps_taskprocessor_pop__386__&tps->taskprocessor_lock In the above, I draw the following conclusions: 1. 1.6 locking and holding times are about, on the average, roughly, twice the time of 1.4. 2. channel_find_locked() is called 3 times in 1.4; it is called almost 7000 times in trunk, and runs approx 6 times slower. Here is a possible candidate. 3. taskprocessor stuff gets called 21,000 times in trunk, but wasn't used at all in 1.4 -- something to look at. 4. We have been "cheating" with trunk. All numbers and hold times with the channel lock call removed from the handle_request_invite. This roughly doubled the performance of chan_sip wrt call setup/teardown speed. It just tends to lock up when you do a "stop gracefully"...