this full log of the call UNMODIFIED with a full sip trace may be able to help answer your questions.
On Apr 18, 2018, at 10:08 AM, Shaun Stokes <shaun.stokes@itec-support.co.uk> wrote:
Hi All,
We have an issue when calling a LUA script with menu options from an H264 video enabled device the call drops part way into the call while navigating a menu due to '500 Server Internal Error'.
Trying to establish if this is a problem our end or a bug, has anyone else experienced this issue before?
Logs from an example below, our IP address is masked as x.x.x.x
nua.c:633 nua_invite() nua: nua_invite: entering nua_stack.c:529 nua_signal() nua(0x7f25b00e8e10): sent signal r_invite nua_stack.c:569 nua_stack_signal() nua(0x7f25b00e8e10): recv signal r_invite nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f25b00f2ce0, ...) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f25b00f2ce0) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4588 tport_by_name() tport(0x7f25b0005100): found 0x7f25b0147320 by name tls/x.x.x.x:7859 tport.c:3257 tport_tsend() tport_tsend(0x7f25b0147320) tpn = tls/x.x.x.x:7859 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f25b00e40c0 0x7f25b001fe60 755 (755) EXECUTE sofia/internal/2001@domain sleep(2000) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f25b00e40c0 0x7f25b01ca460 9 (9) tport.c:3594 tport_vsend() tport_vsend(0x7f25b0147320): 764 bytes of 764 to tls/x.x.x.x:7859 tport.c:3492 tport_send_msg() tport_vsend returned 764 tport.c:2296 tport_set_secondary_timer() tport(0x7f25b0147320): reset timer nta.c:8304 outgoing_send() nta: sent INVITE (121693762) to tls/x.x.x.x:7859 tport.c:4160 tport_pend() tport_pend(0x7f25b0147320): pending 0x7f25b013b770 for tls/x.x.x.x:7859 (already 0) nta.c:1350 set_timeout() nta: timer set to 32000 ms nua_session.c:4145 signal_call_state_change() nua(0x7f25b00e8e10): ready call updated: calling nua_stack.c:269 nua_stack_event() nua(0x7f25b00e8e10): event i_state INVITE sent nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-04-18 14:54:13.139241 [DEBUG] sofia.c:7084 Channel sofia/internal/2001@domain entering state [calling][0] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering tport.c:2773 tport_wakeup() tport_wakeup(0x7f25b0147320): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f25b0147320) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f25b0147320): tls_read() returned 473 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f25b0147320) msg 0x7f25b00d65f0 from (tls/x.x.x.x:7859) has 473 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7f25b0147320): msg 0x7f25b00d65f0 (473 bytes) from tls/x.x.x.x:7859/sips next=(nil) nta.c:3299 agent_recv_response() nta: received 500 Server Internal Error for INVITE (121693762) nta.c:3366 agent_recv_response() nta: 500 Server Internal Error is going to a transaction nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 78.612 ms tport.c:4222 tport_release() tport_release(0x7f25b0147320): 0x7f25b013b770 by 0x7f25b01d3eb0 with 0x7f25b00d65f0 tport.c:4588 tport_by_name() tport(0x7f25b0005100): found 0x7f25b0147320 by name tls/x.x.x.x:7859 tport.c:3257 tport_tsend() tport_tsend(0x7f25b0147320) tpn = tls/x.x.x.x:7859 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f25b00e40c0 0x7f25b011b590 403 (403) tport.c:3594 tport_vsend() tport_vsend(0x7f25b0147320): 403 bytes of 403 to tls/x.x.x.x:7859 tport.c:3492 tport_send_msg() tport_vsend returned 403 tport.c:2296 tport_set_secondary_timer() tport(0x7f25b0147320): reset timer nta.c:8304 outgoing_send() nta: sent ACK (121693762) to tls/x.x.x.x:7859 nta.c:8722 outgoing_free() nta: outgoing_free(0x7f25b0146630) nua_stack.c:271 nua_stack_event() nua(0x7f25b00e8e10): event r_invite 500 Server Internal Error nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:1784 soa_terminate() soa_terminate(static::0x7f25b00f2ce0) called nua_stack.c:359 nua_application_event() nua: nua_application_event: entering soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f25b00f2ce0) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4588 tport_by_name() tport(0x7f25b0005100): found 0x7f25b0147320 by name tls/x.x.x.x:7859 tport.c:3257 tport_tsend() tport_tsend(0x7f25b0147320) tpn = tls/x.x.x.x:7859 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f25b00e40c0 0x7f25b011b590 625 (625) tport.c:3594 tport_vsend() tport_vsend(0x7f25b0147320): 625 bytes of 625 to tls/x.x.x.x:7859 tport.c:3492 tport_send_msg() tport_vsend returned 625 tport.c:2296 tport_set_secondary_timer() tport(0x7f25b0147320): reset timer nta.c:8304 outgoing_send() nta: sent BYE (121693763) to tls/x.x.x.x:7859 tport.c:4160 tport_pend() tport_pend(0x7f25b0147320): pending 0x7f25b01128c0 for tls/x.x.x.x:7859 (already 0) nua_session.c:4139 signal_call_state_change() nua(0x7f25b00e8e10): call state changed: ready -> terminating nua_stack.c:271 nua_stack_event() nua(0x7f25b00e8e10): event i_state 500 Server Internal Error nua_stack.c:359 nua_application_event() nua: nua_application_event: entering tport.c:2296 tport_set_secondary_timer() tport(0x7f25b0147320): reset timer nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-04-18 14:54:13.239253 [DEBUG] sofia.c:7084 Channel sofia/internal/2001@domain entering state [terminating][500] 2018-04-18 14:54:13.239253 [NOTICE] sofia.c:8273 Hangup sofia/internal/2001@domain [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:569 nua_stack_signal() nua(0x7f25b00e8e10): recv signal r_destroy nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f25b00e8e10): removing session usage nua_stack.c:529 nua_signal() nua(0x7f25b00e8e10): sent signal r_destroy nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua_session.c:4139 signal_call_state_change() nua(0x7f25b00e8e10): call state changed: terminating -> terminated nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:269 nua_stack_event() nua(0x7f25b00e8e10): event i_state Terminated nua_stack.c:269 nua_stack_event() nua(0x7f25b00e8e10): event i_terminated Terminated soa.c:356 soa_destroy() soa_destroy(static::0x7f25b00f2ce0) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f25b013afd0) 2018-04-18 14:54:13.239253 [DEBUG] switch_core_session.c:2815 sofia/internal/2001@domain skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-04-18 14:54:13.239253 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f256404f450 released. 2018-04-18 14:54:13.239253 [DEBUG] switch_cpp.cpp:1112 sofia/internal/2001@domain destroy/unlink session from object 2018-04-18 14:54:13.239253 [DEBUG] switch_core_media.c:5970 sofia/internal/2001@domain Video thread ended
Thanks, Shaun
______________________________________________________________________ This message has been checked for all known viruses by MessageLabs Virus Scanning Service. ______________________________________________________________________ _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org <mailto:consulting@freeswitch.org> http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites http://www.freeswitch.org <http://www.freeswitch.org/> http://confluence.freeswitch.org <http://confluence.freeswitch.org/> http://www.cluecon.com <http://www.cluecon.com/>
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org <mailto:FreeSWITCH-users@lists.freeswitch.org> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users> http://www.freeswitch.org <http://www.freeswitch.org/>