from:http://blog.sina.com.cn/s/blog_537d39500100v8yg.html
以下只分析记录关键路径和关键函数:
一、代码分析:
main.c
1、main()函数:
注册一些关键模块:
register_builtin_modules();
解析opensips.cfg配置文件
yyparse();
注:cfg脚本文件的解析是通过lex和yacc工具完成的,通过他们可以使opensips.cfg的执行速度达到c语言级别
枚举本服务器上的所有ip和本服务端口:
fix_all_socket_lists();
2、main_loop()函数:
进入到主要的主循环函数:
main_loop();
如果支持udp,则会启动这个循环:
udp_rcv_loop();
如果支持tcp,则首先调用tcp_init_children()初始化tcp子进程和父进程。
此处很关键,opensips在此函数中,调用socketpair()来构造unix socket对,
分别分配给父进程和子进程,也就是说真正的sip服务,是由子进程来完成的,示例:
“客户端请求->TCP父进程->sendmsg/recvmsg传递socket->子进程接收客户端请求->子进程进行业务处理”
因此每个子进程都在以下这个函数中循环等待父进程转发的请求:
其过程参考的日志如下:
Sep 24 18:30:04 [14405] DBG:core:handle_io: >>>>>>>> come in
Sep 24 18:30:04 [14405] DBG:core:probe_max_sock_buff: getsockopt: snd is initially 262142
Sep 24 18:30:04 [14405] INFO:core:probe_max_sock_buff: using snd buffer of 255 kb
Sep 24 18:30:04 [14405] DBG:core:print_ip: tcpconn_new: new tcp connection to: 113.108.148.114
Sep 24 18:30:04 [14405] DBG:core:tcpconn_new: on port 13599, type 2
Sep 24 18:30:04 [14405] DBG:core:tcpconn_add: hashes: 366, 1
Sep 24 18:30:04 [14405] DBG:core:handle_new_connect: new connection: 0x2b0f383704c0 35 flags: 0002
Sep 24 18:30:04 [14405] DBG:core:send2child: to tcp child 0 0(14397), 0x2b0f383704c0
Sep 24 18:30:04 [14397] DBG:core:handle_io: received n=8 con=0x2b0f383704c0, fd=30
Sep 24 18:30:04 [14397] DBG:core:io_watch_add: io_watch_add(0x779b40, 30, 2, 0x2b0f383704c0), fd_no=1
Sep 24 18:30:04 [14397] DBG:core:tcp_read_req: >>>>>>>>> come in tcp_read_req function now !
Sep 24 18:30:04 [14397] DBG:core:tcp_read_req: content-length= 481
Sep 24 18:30:04 [14397] DBG:core:receive_msg: >>>> recv msg=
在初始化完父子进程后,则启动外部连接的监听循环:
tcp_main_loop()
tcp_main_loop()此函数中多次调用io_watch_add(),用于添加所需要的监听端口;
进入main_loop循环,在此循环中,根据支持的epoll/select/poll等方式来等待客户端连接
以io_wait_loop_poll()为例继续分析:
在此函数中,循环检查所有的socket,当发现可读或可写之后,调用handle_io()函数处理。
tcp_main.c
当有新连接请求时,通过handle_io()函数中的handle_new_connect()处理:
tcp_main.c文件:
在handle_new_connect()函数中,先接受客户端的请求,然后把此socket通过sendmsg方式,
发送给TCP子进程处理(请参考sendmsg/recvmsg来传递socket的方式 / SOL_SOCKET,参考上述章节部分描述):
此时,父进程在tcp_receive_loop()函数的循环中捕获了这个请求,因此进入tcp_read.c文件中的tcp_read_req()函数,
tcp_read.c文件:
继续进入最重要的处理函数 receive_msg():
receive.c文件:
在receive_msg()函数中,首先解析客户端的请求消息:
解析消息完成后,进入cfg配置文件的脚步处理过程,非常关键:
此函数接连调用action.c文件中的函数:run_actions(), run_action_list(), do_action(),
最后的do_action()函数,负责对脚本的逐步解析和处理,由下一章节专门处理。
在receive_msg()函数处理完成后,总会看到这行日志:
二、opensips.cfg的配置文件解析过程示例:
sip业务的处理逻辑,是由opensips.cfg配置文件后半部分的脚本来处理的,其中的
处理函数就是action.c文件中的do_action(),我在此函数开始部分增加了一行调试日志:
LM_DBG(">>>>>
有助于分析每一步脚本的执行,其中if代表type=14, 执行module函数代表type=15,xlog代表type=73等等,
可以参考以下日志来理解这个脚本的控制:
Sep 23 19:41:51 [4580] DBG:core:receive_msg: After parse_msg...
Sep 23 19:41:51 [4580] DBG:core:receive_msg: preparing to run routing scripts...
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:parse_headers: flags=100
Sep 23 19:41:51 [4580] DBG:core:parse_to: end of header reached, state=10
Sep 23 19:41:51 [4580] DBG:core:parse_to: display={}, ruri={sip:max@121.14.161.187}
Sep 23 19:41:51 [4580] DBG:core:get_hdr_field: <To> [26]; uri=[sip:max@121.14.161.187]
Sep 23 19:41:51 [4580] DBG:core:get_hdr_field: to body [<sip:max@121.14.161.187>
]
Sep 23 19:41:51 [4580] DBG:core:get_hdr_field: cseq <CSeq>: <21> <INVITE>
Sep 23 19:41:51 [4580] DBG:maxfwd:is_maxfwd_present: value = 70
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:uri:has_totag: no totag
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:parse_headers: flags=78
Sep 23 19:41:51 [4580] DBG:tm:t_lookup_request: start searching: hash=43376, isACK=0
Sep 23 19:41:51 [4580] DBG:tm:matching_3261: RFC3261 transaction matching failed
Sep 23 19:41:51 [4580] DBG:tm:t_lookup_request: no transaction found
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:parse_to_param: tag=1829577472
Sep 23 19:41:51 [4580] DBG:core:parse_to: end of header reached, state=29
Sep 23 19:41:51 [4580] DBG:core:parse_to: display={}, ruri={sip:max5@121.14.161.187}
Sep 23 19:41:51 [4580] DBG:core:grep_sock_info: checking if host==us: 14==9 &&
Sep 23 19:41:51 [4580] DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Sep 23 19:41:51 [4580] DBG:core:grep_sock_info: checking if host==us: 14==14 &&
Sep 23 19:41:51 [4580] DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:auth:check_nonce: comparing [4e7c709d000000115b6b5404
Sep 23 19:41:51 [4580] DBG:db_mysql:has_stmt_ctx: ctx found for subscriber
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_do_prepared_query: conn=0x7c8610 (tail=8146720) MC=0x7c6028
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_val2bind: added val (0): len=4; type=254; is_null=0
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_do_prepared_query: prepared statement has 1 columns in result
Sep 23 19:41:51 [4580] DBG:core:db_new_result: allocate 48 bytes for result set at 0x7d7cc0
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query
Sep 23 19:41:51 [4580] DBG:core:db_allocate_columns: allocate 28 bytes for result columns at 0x7d7728
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7d7730)[0]=[password]
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Sep 23 19:41:51 [4580] DBG:core:db_allocate_rows: allocate 48 bytes for result rows and values at 0x7d79a0
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_str2val: converting STRING [max]
Sep 23 19:41:51 [4580] DBG:auth_db:get_ha1: HA1 string calculated: f213458fbed991c73058baa7
Sep 23 19:41:51 [4580] DBG:auth:check_response: our result = 'e9dc8829d555d4f028ee2b30
Sep 23 19:41:51 [4580] DBG:auth:check_response: authorization is OK
Sep 23 19:41:51 [4580] DBG:auth:post_auth: nonce index= 17
Sep 23 19:41:51 [4580] DBG:core:db_free_columns: freeing result columns at 0x7d7728
Sep 23 19:41:51 [4580] DBG:core:db_free_rows: freeing 1 rows
Sep 23 19:41:51 [4580] DBG:core:db_free_row: freeing row values at 0x7d79b0
Sep 23 19:41:51 [4580] DBG:core:db_free_rows: freeing rows at 0x7d79a0
Sep 23 19:41:51 [4580] DBG:core:db_free_result: freeing result set at 0x7d7cc0
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:uri:check_username: Digest username and URI username match
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:parse_headers: flags=200
Sep 23 19:41:51 [4580] DBG:core:get_hdr_field: content_length=388
Sep 23 19:41:51 [4580] DBG:core:get_hdr_field: found end of header
Sep 23 19:41:51 [4580] DBG:rr:find_first_route: No Route headers found
Sep 23 19:41:51 [4580] DBG:rr:loose_route: There is no Route HF
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:grep_sock_info: checking if host==us: 14==9 &&
Sep 23 19:41:51 [4580] DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Sep 23 19:41:51 [4580] DBG:core:grep_sock_info: checking if host==us: 14==14 &&
Sep 23 19:41:51 [4580] DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:db_new_result: allocate 48 bytes for result set at 0x7d92a0
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
Sep 23 19:41:51 [4580] DBG:core:db_allocate_columns: allocate 56 bytes for result columns at 0x7d9308
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7d9318)[0]=[username]
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7d9328)[1]=[domain]
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Sep 23 19:41:51 [4580] DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query
Sep 23 19:41:51 [4580] DBG:alias_db:alias_db_query: no alias found for R-URI
Sep 23 19:41:51 [4580] DBG:core:db_free_columns: freeing result columns at 0x7d9308
Sep 23 19:41:51 [4580] DBG:core:db_free_rows: freeing 0 rows
Sep 23 19:41:51 [4580] DBG:core:db_free_result: freeing result set at 0x7d92a0
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] INFO:core:buf_init: initializing...
----------- come here before lookup -------------
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:registrar:lookup: setting as ruri <sip:max@192.168.161.36;line=dc4c7833fc0bc50>
Sep 23 19:41:51 [4580] DBG:registrar:lookup: looking for branches
Sep 23 19:41:51 [4580] DBG:registrar:lookup: setting branch <sip:max@113.108.148.114:3879;line=dc4c7833fc0bc50>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
----------- come here before setflag -------------
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
----------- come here in route 1 -------------
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:tm:t_newtran: transaction on entrance=(nil)
Sep 23 19:41:51 [4580] DBG:core:parse_headers: flags=ffffffffffffffff
Sep 23 19:41:51 [4580] DBG:core:parse_headers: flags=78
Sep 23 19:41:51 [4580] DBG:tm:t_lookup_request: start searching: hash=43376, isACK=0
Sep 23 19:41:51 [4580] DBG:tm:matching_3261: RFC3261 transaction matching failed
Sep 23 19:41:51 [4580] DBG:tm:t_lookup_request: no transaction found
Sep 23 19:41:51 [4580] DBG:tm:run_reqin_callbacks: trans=0x2b3767cd3a20, callback type 1, id 0 entered
Sep 23 19:41:51 [4580] DBG:core:parse_headers: flags=78
Sep 23 19:41:51 [4580] DBG:core:parse_headers: flags=ffffffffffffffff
Sep 23 19:41:51 [4580] DBG:core:check_ip_address: params 113.108.148.114, 192.168.172.142, 0
Sep 23 19:41:51 [4580] DBG:core:_shm_resize: resize(0) called
Sep 23 19:41:51 [4580] DBG:core:tcp_send: tcp connection found (0x2b3767cc3880), acquiring fd
Sep 23 19:41:51 [4580] DBG:core:tcp_send: c= 0x2b3767cc3880, n=16
Sep 23 19:41:51 [4589] DBG:core:handle_ser_child: read response= 2b3767cc3880, 1, fd -1 from 16 (4580)
Sep 23 19:41:51 [4580] DBG:core:tcp_send: after receive_fd: c= 0x2b3767cc3880 n=8 fd=31
Sep 23 19:41:51 [4580] DBG:core:tcp_send: sending...
Sep 23 19:41:51 [4580] DBG:core:tcp_send: after write: c= 0x2b3767cc3880 n=308 fd=31
Sep 23 19:41:51 [4580] DBG:core:tcp_send: buf=
SIP/2.0 100 Giving a try
Via: SIP/2.0/TCP 192.168.172.142:1168;rport=6767;branch=z9hG4bK2121284540;received=113.108.148.114
From: <sip:max5@121.14.161.187>;tag=1829577472
To: <sip:max@121.14.161.187>
Call-ID: 94874130
CSeq: 21 INVITE
Server: OpenSIPS (1.7.0-notls (x86_64/linux))
Content-Length: 0
Sep 23 19:41:51 [4580] DBG:tm:_reply_light: reply sent out. buf=0x7da3a0: SIP/2.0 1..., shmem=0x2b3767cd6fb8: SIP/2.0 1
Sep 23 19:41:51 [4580] DBG:tm:_reply_light: finished
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
new branch at sip:max@192.168.161.36;line=dc4c7833fc0bc50
Sep 23 19:41:51 [4580] DBG:core:mk_proxy: >>>> doing DNS lookup...name=⊕}, port=0
Sep 23 19:41:51 [4580] DBG:core:build_req_buf_from_sip_req: id added: <;i=4>, rcv proto=2
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
new branch at sip:max@113.108.148.114:3879;line=dc4c7833fc0bc50
Sep 23 19:41:51 [4580] DBG:core:mk_proxy: >>>> doing DNS lookup...name=甫}, port=3879
Sep 23 19:41:51 [4580] DBG:core:build_req_buf_from_sip_req: id added: <;i=4>, rcv proto=2
Sep 23 19:41:51 [4580] DBG:tm:set_timer: relative timeout is 500000
Sep 23 19:41:51 [4580] DBG:tm:insert_timer_unsafe: [4]: 0x2b3767cd3c40 (447300000)
Sep 23 19:41:51 [4580] DBG:tm:set_timer: relative timeout is 30
Sep 23 19:41:51 [4580] DBG:tm:insert_timer_unsafe: [0]: 0x2b3767cd3c70 (476)
Sep 23 19:41:51 [4580] DBG:tm:set_timer: relative timeout is 500000
Sep 23 19:41:51 [4580] DBG:tm:insert_timer_unsafe: [4]: 0x2b3767cd3e40 (447300000)
Sep 23 19:41:51 [4580] DBG:tm:set_timer: relative timeout is 30
Sep 23 19:41:51 [4580] DBG:tm:insert_timer_unsafe: [0]: 0x2b3767cd3e70 (476)
Sep 23 19:41:51 [4580] DBG:tm:t_relay_to: new transaction fwd'ed
Sep 23 19:41:51 [4580] DBG:core:do_action: >>>>>
Sep 23 19:41:51 [4580] DBG:tm:t_unref: UNREF_UNSAFE: [0x2b3767cd3a20] after is 0
Sep 23 19:41:51 [4580] DBG:core:destroy_avp_list: destroying list (nil)
Sep 23 19:41:51 [4580] DBG:core:receive_msg: cleaning up
三、我的配置文件参考如下,可以对应上述的日志进行分析:
#
# $Id: opensips.cfg 8141 2011-07-08 12:17:13Z vladut-paiu $
#
# OpenSIPS basic configuration script
#
#
# Please refer to the Core CookBook at:
#
# for a explanation of possible statements, functions and parameters.
#
####### Global Parameters #########
debug=10
log_stderror=yes
log_facility=LOG_LOCAL0
fork=yes
children=4
#debug=6
#fork=no
#log_stderror=yes
#disable_tcp=yes
#disable_dns_blacklist=no
#dns_try_ipv6=yes
#auto_aliases=no
#disable_tls = no
#listen = tls:your_IP:5061
#tls_verify_server = 1
#tls_verify_client = 1
#tls_require_client_certificate = 0
#tls_method = TLSv1
#tls_certificate = "/home/max/opensips//etc/opensips/tls/user/user-cert.pem"
#tls_private_key = "/home/max/opensips//etc/opensips/tls/user/user-privkey.pem"
#tls_ca_list = "/home/max/opensips//etc/opensips/tls/user/user-calist.pem"
# default db_url to be used by modules requiring DB connection
db_default_url="mysql://opensips:open2011@127.0.0.1:8306/opensips"
port=5060
#listen=udp:192.168.1.2:5060
####### Modules Section ########
#set module path
mpath="/home/max/opensips//lib64/opensips/modules/"
loadmodule "db_mysql.so"
loadmodule "signaling.so"
loadmodule "sl.so"
loadmodule "tm.so"
loadmodule "rr.so"
loadmodule "maxfwd.so"
loadmodule "usrloc.so"
loadmodule "registrar.so"
loadmodule "textops.so"
loadmodule "mi_fifo.so"
loadmodule "uri.so"
loadmodule "acc.so"
loadmodule "auth.so"
loadmodule "auth_db.so"
loadmodule "alias_db.so"
loadmodule "domain.so"
#loadmodule "presence.so"
#loadmodule "presence_xml.so"
# ----------------- setting module-specific parameters ---------------
# ----- mi_fifo params -----
modparam("mi_fifo", "fifo_name", "/tmp/opensips_fifo")
# ----- rr params -----
# do not append from tag to the RR (no need for this script)
modparam("rr", "append_fromtag", 0)
# ----- registrar params -----
#modparam("registrar", "max_contacts", 10)
# ----- usrloc params -----
#modparam("usrloc", "db_mode",
#modparam("usrloc", "db_mode",
#modparam("usrloc", "db_url",
#
# ----- uri params -----
modparam("uri", "use_uri_table", 0)
# ----- acc params -----
modparam("acc", "early_media", 1)
modparam("acc", "report_cancels", 1)
modparam("acc", "detect_direction", 0)
modparam("acc", "failed_transaction_flag", 3)
modparam("acc", "log_flag", 1)
modparam("acc", "log_missed_flag", 2)
modparam("acc", "db_flag", 1)
modparam("acc", "db_missed_flag", 2)
# ----- auth_db params -----
modparam("auth_db", "calculate_ha1", yes)
modparam("auth_db", "password_column", "password")
modparam("auth_db", "db_url",
modparam("auth_db", "load_credentials", "")
# ----- alias_db params -----
modparam("alias_db", "db_url",
# ----- domain params -----
#modparam("domain", "db_url",
#
#modparam("domain", "db_mode", 1)
# ----- multi-module params -----
#modparam("auth_db|usrloc|uri", "use_domain", 1)
# ----- presence params -----
#modparam("presence|presence_xml", "db_url",
#
#modparam("presence_xml", "force_active", 1)
#modparam("presence", "server_address", "sip:192.168.1.2:5060")
####### Routing Logic ########
# main request routing logic
route{
}
route[1] {
}
# Presence route
#route[2]
#{
#
#
#
#
#
#
#
#
#
#
#
#
#
#
#
#
#
#}
branch_route[2] {
}
onreply_route[2] {
}
failure_route[1] {
}