[Freeswitch-users] hangup with cause:WRONG_CALL_STATE
李俊俊
rockxsj at gmail.com
Tue Apr 29 11:51:12 MSD 2014
I have found the problem,It is because of the client send register message
every 5s.Now I have disable-register in sofia profile.
2014-04-28 14:02 GMT+00:00 李俊俊 <rockxsj at gmail.com>:
> I add some code to log the pop function,just like below:
> switch_mutex_lock(mod_sofia_globals.mutex);
> n = msg_queue_threads;
> msg_queue_threads++;
> switch_mutex_unlock(mod_sofia_globals.mutex);
>
> switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_WARNING, "MSG Thread %d
> Started\n", my_id);
>
>
> for(;;) {
>
> if (switch_queue_pop(q, &pop) != SWITCH_STATUS_SUCCESS) {
> switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_WARNING, "POP FAIL
> %s\n", "SELF");
> switch_cond_next();
> continue;
> }
>
> if (pop) {
> sofia_dispatch_event_t *de = (sofia_dispatch_event_t *) pop;
> switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_WARNING, "MSG Thread %d
> Dispatcher Started\n", n);
> sofia_process_dispatch_event(&de);
> switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_WARNING, "MSG Thread %d
> Dispatcher Ended\n", n);
> } else {
> break;
> }
> }
>
> And I got logs like below:
> 2014-04-28 21:23:54.229117 [WARNING] sofia.c:1922 MSG Thread 0 Dispatcher
> Started
> 2014-04-28 21:23:54.229174 [WARNING] sofia.c:1924 MSG Thread 0 Dispatcher
> Ended
> 2014-04-28 21:23:54.231115 [WARNING] sofia.c:1922 MSG Thread 0 Dispatcher
> Started
> 2014-04-28 21:23:54.231137 [WARNING] sofia.c:1924 MSG Thread 0 Dispatcher
> Ended
> 2014-04-28 21:23:54.894118 [WARNING] sofia.c:1922 MSG Thread 0 Dispatcher
> Started
> 2014-04-28 21:23:54.894157 [WARNING] sofia.c:1924 MSG Thread 0 Dispatcher
> Ended
> 2014-04-28 21:23:54.894232 [WARNING] sofia.c:1922 MSG Thread 0 Dispatcher
> Started
> 2014-04-28 21:23:55.200100 [WARNING] sofia.c:1924 MSG Thread 0 Dispatcher
> Ended
> 2014-04-28 21:23:55.200127 [WARNING] sofia.c:1922 MSG Thread 0 Dispatcher
> Started
> 2014-04-28 21:23:55.540108 [WARNING] sofia.c:1924 MSG Thread 0 Dispatcher
> Ended
> 2014-04-28 21:23:55.540108 [WARNING] sofia.c:1922 MSG Thread 0 Dispatcher
> Started
> 2014-04-28 21:23:55.840114 [WARNING] sofia.c:1924 MSG Thread 0 Dispatcher
> Ended
> 2014-04-28 21:23:55.840114 [WARNING] sofia.c:1922 MSG Thread 0 Dispatcher
> Started
> 2014-04-28 21:23:55.840114 [WARNING] sofia.c:1924 MSG Thread 0 Dispatcher
> Ended
> 2014-04-28 21:23:55.840114 [WARNING] sofia.c:1922 MSG Thread 0 Dispatcher
> Started
> 2014-04-28 21:23:56.100116 [WARNING] sofia.c:1924 MSG Thread 0 Dispatcher
> Ended
> 2014-04-28 21:23:56.100116 [WARNING] sofia.c:1922 MSG Thread 0 Dispatcher
> Started
> 2014-04-28 21:23:56.380119 [WARNING] sofia.c:1924 MSG Thread 0 Dispatcher
> Ended
>
> I found it is too long between a pop ended and other stated.I think this
> will make the pop function execute slow than push.Will it?
>
>
> 2014-04-28 21:22 GMT+08:00 Michael Jerris <mike at jerris.com>:
>
>> This is a completely different issue than i was talking about. What rate
>> of traffic are you putting on this box? it seems your box is way
>> underpowered for whatever your doing, or your using something to lookup
>> users or something of the sort that is blocking or taking way too long.
>>
>> On Apr 28, 2014, at 9:07 AM, 李俊俊 <rockxsj at gmail.com> wrote:
>>
>> Yes,my code is pulled from the master branch on 4.23.It <http://4.23.it/>seems that the push is fast than pop.I add some code to log the queue
>> length,just like below:
>> if (!sofia_private) {
>> if (sess_count >= sess_max || !sofia_test_pflag(profile, PFLAG_RUNNING)
>> || !switch_core_ready_inbound()) {
>> nua_respond(nh, 503, "Maximum Calls In Progress",
>> SIPTAG_RETRY_AFTER_STR("300"), NUTAG_WITH_THIS(nua), TAG_END());
>> goto end;
>> }
>>
>> switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG,
>> "switch_queue_size(mod_sofia_globals.msg_queue):%d\n",
>> switch_queue_size(mod_sofia_globals.msg_queue));
>> switch_log_printf(SWITCH_CHANNEL_LOG, SWITCH_LOG_DEBUG,
>> "critical:%d\n", (unsigned int)critical);
>>
>> if (switch_queue_size(mod_sofia_globals.msg_queue) > (unsigned
>> int)critical) {
>> nua_respond(nh, 503, "System Busy", SIPTAG_RETRY_AFTER_STR("300"),
>> NUTAG_WITH_THIS(nua), TAG_END());
>> goto end;
>> }
>>
>> if (sofia_test_pflag(profile, PFLAG_STANDBY)) {
>> nua_respond(nh, 503, "System Paused", NUTAG_WITH_THIS(nua), TAG_END());
>> goto end;
>> }
>> }
>>
>> And I found the switch_queue_size(mod_sofia_globals.msg_queue) is
>> increase so fast and almost did not decrease,the below is the log:
>> 2014-04-28 18:55:31.416405 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56157
>> 2014-04-28 18:55:31.436402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56158
>> 2014-04-28 18:55:31.436402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56159
>> 2014-04-28 18:55:31.476402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56160
>> 2014-04-28 18:55:31.496402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56161
>> 2014-04-28 18:55:31.496402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56162
>> 2014-04-28 18:55:31.496402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56163
>> 2014-04-28 18:55:31.516402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56164
>> 2014-04-28 18:55:31.516402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56165
>> 2014-04-28 18:55:31.536402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56166
>> 2014-04-28 18:55:31.556402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56167
>> 2014-04-28 18:55:31.576407 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56168
>> 2014-04-28 18:55:31.576407 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56169
>> 2014-04-28 18:55:31.576407 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56170
>> 2014-04-28 18:55:31.596403 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56171
>> 2014-04-28 18:55:31.616404 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56169
>> 2014-04-28 18:55:31.636404 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56170
>> 2014-04-28 18:55:31.656403 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56172
>> 2014-04-28 18:55:31.656403 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56173
>> 2014-04-28 18:55:31.656403 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56174
>> 2014-04-28 18:55:31.676404 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56175
>> 2014-04-28 18:55:31.676404 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56175
>> 2014-04-28 18:55:31.716404 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56177
>> 2014-04-28 18:55:31.716404 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56178
>> 2014-04-28 18:55:31.756407 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56180
>> 2014-04-28 18:55:31.756407 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56181
>> 2014-04-28 18:55:31.756407 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56182
>> 2014-04-28 18:55:31.756407 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56183
>> 2014-04-28 18:55:31.776414 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56184
>> 2014-04-28 18:55:31.796402 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56185
>> 2014-04-28 18:55:31.836415 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56179
>> 2014-04-28 18:55:31.856415 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56180
>> 2014-04-28 18:55:31.896415 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56183
>> 2014-04-28 18:55:31.896415 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56184
>> 2014-04-28 18:55:31.896415 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56185
>> 2014-04-28 18:55:31.916416 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56186
>> 2014-04-28 18:55:31.916416 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56187
>> 2014-04-28 18:55:31.916416 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56188
>> 2014-04-28 18:55:31.936415 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56189
>> 2014-04-28 18:55:31.936415 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56190
>> 2014-04-28 18:55:31.936415 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56191
>> 2014-04-28 18:55:31.996416 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56192
>> 2014-04-28 18:55:32.036417 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56194
>> 2014-04-28 18:55:32.036417 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56195
>> 2014-04-28 18:55:32.036417 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56196
>> 2014-04-28 18:55:32.056417 [DEBUG] sofia.c:2081
>> switch_queue_size(mod_sofia_globals.msg_queue):56197
>>
>>
>> Can you confirm again?
>>
>>
>> 2014-04-28 20:03 GMT+08:00 Michael Jerris <mike at jerris.com>:
>>
>>> I think we have already fixed this bug. Have you tried updating to more
>>> recent code?
>>>
>>> On Apr 28, 2014, at 7:46 AM, rockxsj <rockxsj at gmail.com> wrote:
>>>
>>> Hi guys!
>>>
>>> I found that the some of the incoming call will hangup with case:
>>> WRONG_CALL_STATE,but else will be ok.After a hour,almost every incoming
>>> call will be hangup with the same cause.Then I will restart the
>>> freeswitch,it will server like before:some call will be hangup with the
>>> cause...
>>>
>>> 28e10f2e-c851-11e3-a146-85a8fadad1b0 2014-04-20 14:01:15.498169
>>> [WARNING] switch_core_state_machine.c:567
>>> 28e10f2e-c851-11e3-a146-85a8fadad1b0 sofia/internal/123456 at sipsj.236.cnAbandoned
>>> 28e10f2e-c851-11e3-a146-85a8fadad1b0 2014-04-20 14:01:15.498169 [NOTICE]
>>> switch_core_state_machine.c:570 Hangup
>>> sofia/internal/123456 at sipsj.236.cn [CS_NEW] [WRONG_CALL_STATE]
>>>
>>> What does Wrong call state mean and what can I do to fix this issue?
>>>
>>> Everything else is working. I can make outgoing calls and call other
>>> extensions.
>>>
>>> Thanks in advance.
>>>
>>>
>>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>>
>>
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://wiki.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>> http://www.freeswitch.org
>>
>>
>
>
> --
> 个人主页：http://yazi.whoknow.me
>
--
个人主页：http://yazi.whoknow.me
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140429/777de7e9/attachment-0001.html
Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-users
mailing list