diff options
| author | Benny Prijono <bennylp@teluu.com> | 2006-01-07 18:44:25 +0000 |
|---|---|---|
| committer | Benny Prijono <bennylp@teluu.com> | 2006-01-07 18:44:25 +0000 |
| commit | 57b75697969b3cfd0cc5fe6ca3c98b38acc16608 (patch) | |
| tree | bca6c76392e15dcc6447919313eadf835138269d /pjsip | |
| parent | 9b1fe4bbb2a30ea94d3ff33989341c656936d930 (diff) | |
Added test functions for UAC transaction
git-svn-id: http://svn.pjsip.org/repos/pjproject/trunk@109 74dad513-b988-da41-8d7b-12977e46ad98
Diffstat (limited to 'pjsip')
28 files changed, 2154 insertions, 530 deletions
diff --git a/pjsip/build/pjsip_core.dsp b/pjsip/build/pjsip_core.dsp index 608d7a6a..bdc54dd1 100644 --- a/pjsip/build/pjsip_core.dsp +++ b/pjsip/build/pjsip_core.dsp @@ -127,8 +127,6 @@ SOURCE=..\src\pjsip\sip_transaction.c !IF "$(CFG)" == "pjsip_core - Win32 Release"
-# PROP Exclude_From_Build 1
-
!ELSEIF "$(CFG)" == "pjsip_core - Win32 Debug"
!ENDIF
diff --git a/pjsip/build/test_pjsip.dsp b/pjsip/build/test_pjsip.dsp index 649a8ae7..8e75079b 100644 --- a/pjsip/build/test_pjsip.dsp +++ b/pjsip/build/test_pjsip.dsp @@ -93,6 +93,10 @@ SOURCE="..\src\test-pjsip\main.c" # End Source File
# Begin Source File
+SOURCE="..\src\test-pjsip\msg_logger.c"
+# End Source File
+# Begin Source File
+
SOURCE="..\src\test-pjsip\msg_test.c"
# End Source File
# Begin Source File
@@ -113,6 +117,10 @@ SOURCE="..\src\test-pjsip\transport_udp_test.c" # End Source File
# Begin Source File
+SOURCE="..\src\test-pjsip\tsx_basic_test.c"
+# End Source File
+# Begin Source File
+
SOURCE="..\src\test-pjsip\tsx_uac_test.c"
# End Source File
# Begin Source File
diff --git a/pjsip/include/pjsip/sip_errno.h b/pjsip/include/pjsip/sip_errno.h index 253e6c00..7c3dbbd2 100644 --- a/pjsip/include/pjsip/sip_errno.h +++ b/pjsip/include/pjsip/sip_errno.h @@ -23,6 +23,11 @@ PJ_BEGIN_DECL +/** + * Guidelines on error message length. + */ +#define PJSIP_ERR_MSG_SIZE 64 + /* * PJSIP error codes occupies 170000 - 219000, and mapped as follows: * - 170100 - 170799: mapped to SIP status code in response msg. @@ -86,6 +91,11 @@ PJ_DECL(pj_str_t) pjsip_strerror( pj_status_t status, char *buffer, * SIP object with the same type already exists. */ #define PJSIP_ETYPEEXISTS (PJSIP_ERRNO_START_PJSIP + 2) /* 171002 */ +/** + * @hideinitializer + * SIP stack is shutting down. + */ +#define PJSIP_ESHUTDOWN (PJSIP_ERRNO_START_PJSIP + 3) /* 171003 */ /************************************************************ diff --git a/pjsip/include/pjsip/sip_module.h b/pjsip/include/pjsip/sip_module.h index 0f188194..161e43d2 100644 --- a/pjsip/include/pjsip/sip_module.h +++ b/pjsip/include/pjsip/sip_module.h @@ -133,6 +133,28 @@ struct pjsip_module pj_bool_t (*on_rx_response)(pjsip_rx_data *rdata); /** + * Called to process outgoing request. + * + * @param tdata The outgoing request message. + * + * @return Module should return PJ_SUCCESS in all cases. + * If non-zero (or PJ_FALSE) is returned, the message + * will not be sent. + */ + pj_status_t (*on_tx_request)(pjsip_tx_data *tdata); + + /** + * Called to process outgoing response message. + * + * @param tdata The outgoing response message. + * + * @return Module should return PJ_SUCCESS in all cases. + * If non-zero (or PJ_FALSE) is returned, the message + * will not be sent. + */ + pj_status_t (*on_tx_response)(pjsip_tx_data *tdata); + + /** * Called when this module is acting as transaction user for the specified * transaction, when the transaction's state has changed. * @@ -150,9 +172,10 @@ struct pjsip_module */ enum pjsip_module_priority { - PJSIP_MOD_PRIORITY_TSX_LAYER = 4, - PJSIP_MOD_PRIORITY_UA_PROXY_LAYER = 16, - PJSIP_MOD_PRIORITY_APPLICATION = 32, + PJSIP_MOD_PRIORITY_TRANSPORT_LAYER = 8, + PJSIP_MOD_PRIORITY_TSX_LAYER = 16, + PJSIP_MOD_PRIORITY_UA_PROXY_LAYER = 32, + PJSIP_MOD_PRIORITY_APPLICATION = 64, }; diff --git a/pjsip/include/pjsip/sip_msg.h b/pjsip/include/pjsip/sip_msg.h index 29bd9766..229f2c77 100644 --- a/pjsip/include/pjsip/sip_msg.h +++ b/pjsip/include/pjsip/sip_msg.h @@ -376,6 +376,7 @@ typedef enum pjsip_status_code PJSIP_SC_PROGRESS = 183, PJSIP_SC_OK = 200, + PJSIP_SC_ACCEPTED = 202, PJSIP_SC_MULTIPLE_CHOICES = 300, PJSIP_SC_MOVED_PERMANENTLY = 301, @@ -399,6 +400,7 @@ typedef enum pjsip_status_code PJSIP_SC_UNSUPPORTED_URI_SCHEME = 416, PJSIP_SC_BAD_EXTENSION = 420, PJSIP_SC_EXTENSION_REQUIRED = 421, + PJSIP_SC_SESSION_TIMER_TOO_SMALL = 422, PJSIP_SC_INTERVAL_TOO_BRIEF = 423, PJSIP_SC_TEMPORARILY_UNAVAILABLE = 480, PJSIP_SC_CALL_TSX_DOES_NOT_EXIST = 481, @@ -409,6 +411,8 @@ typedef enum pjsip_status_code PJSIP_SC_BUSY_HERE = 486, PJSIP_SC_REQUEST_TERMINATED = 487, PJSIP_SC_NOT_ACCEPTABLE_HERE = 488, + PJSIP_SC_UNKNOWN_EVENT = 489, + PJSIP_SC_REQUEST_UPDATED = 490, PJSIP_SC_REQUEST_PENDING = 491, PJSIP_SC_UNDECIPHERABLE = 493, @@ -419,6 +423,7 @@ typedef enum pjsip_status_code PJSIP_SC_SERVER_TIMEOUT = 504, PJSIP_SC_VERSION_NOT_SUPPORTED = 505, PJSIP_SC_MESSAGE_TOO_LARGE = 513, + PJSIP_SC_PRECONDITION_FAILURE = 580, PJSIP_SC_BUSY_EVERYWHERE = 600, PJSIP_SC_DECLINE = 603, @@ -426,7 +431,7 @@ typedef enum pjsip_status_code PJSIP_SC_NOT_ACCEPTABLE_ANYWHERE = 606, PJSIP_SC_TSX_TIMEOUT = 701, - PJSIP_SC_TSX_RESOLVE_ERROR = 702, + //PJSIP_SC_TSX_RESOLVE_ERROR = 702, PJSIP_SC_TSX_TRANSPORT_ERROR = 703, } pjsip_status_code; diff --git a/pjsip/include/pjsip/sip_transaction.h b/pjsip/include/pjsip/sip_transaction.h index 5d2a5126..4a7305ec 100644 --- a/pjsip/include/pjsip/sip_transaction.h +++ b/pjsip/include/pjsip/sip_transaction.h @@ -92,6 +92,7 @@ struct pjsip_transaction * Transport. */ pjsip_transport *transport; /**< Transport to use. */ + pj_bool_t is_reliable; /**< Transport is reliable. */ pj_sockaddr addr; /**< Destination address. */ int addr_len; /**< Address length. */ pjsip_response_addr res_addr; /**< Response address. */ @@ -189,11 +190,16 @@ PJ_DECL(pj_status_t) pjsip_tsx_create_uas( pjsip_module *tsx_user, /** * Transmit message in tdata with this transaction. It is possible to - * pass NULL in tdata for UAC transaction, which in this case the request - * message which was specified in #pjsip_tsx_create_uac() will be sent. + * pass NULL in tdata for UAC transaction, which in this case the last message + * or the request message which was specified in #pjsip_tsx_create_uac() + * will be sent. + * + * This function decrements the reference counter of the transmit buffer. * * @param tsx The transaction. - * @param tdata The outgoing message. + * @param tdata The outgoing message. If NULL is specified, then the + * last message transmitted (or the message specified + * in UAC initialization) will be sent. * * @return PJ_SUCCESS if successfull. */ diff --git a/pjsip/include/pjsip/sip_transport.h b/pjsip/include/pjsip/sip_transport.h index c296054c..f2cce0f6 100644 --- a/pjsip/include/pjsip/sip_transport.h +++ b/pjsip/include/pjsip/sip_transport.h @@ -109,6 +109,15 @@ pjsip_transport_get_flag_from_type( pjsip_transport_type_e type ); PJ_DECL(int) pjsip_transport_get_default_port_for_type(pjsip_transport_type_e type); +/** + * Get transport type name. + * + * @param t Transport type. + * + * @return Transport name. + */ +PJ_DECL(const char*) pjsip_transport_get_type_name(pjsip_transport_type_e t); + /***************************************************************************** * @@ -203,6 +212,11 @@ struct pjsip_rx_data /** The parsed message, if any. */ pjsip_msg *msg; + /** Short description about the message. + * Application should use #pjsip_rx_data_get_info() instead. + */ + char *info; + /** The Call-ID header as found in the message. */ pj_str_t call_id; @@ -259,6 +273,15 @@ struct pjsip_rx_data }; +/** + * Get printable information about the message in the rdata. + * + * @param rdata The receive data buffer. + * + * @return Printable information. + */ +PJ_DECL(char*) pjsip_rx_data_get_info(pjsip_rx_data *rdata); + /***************************************************************************** * @@ -303,6 +326,12 @@ struct pjsip_tx_data /** A name to identify this buffer. */ char obj_name[PJ_MAX_OBJ_NAME]; + /** Short information describing this buffer and the message in it. + * Application should use #pjsip_tx_data_get_info() instead of + * directly accessing this member. + */ + char *info; + /** For response message, this contains the reference to timestamp when * the original request message was received. The value of this field * is set when application creates response message to a request by @@ -339,6 +368,18 @@ struct pjsip_tx_data /** Transport manager internal. */ void *token; void (*cb)(void*, pjsip_tx_data*, pj_ssize_t); + + /** Transport information, only valid during on_tx_request() and + * on_tx_response() callback. + */ + struct + { + pjsip_transport *transport; /**< Transport being used. */ + pj_sockaddr dst_addr; /**< Destination address. */ + int dst_addr_len; /**< Length of address. */ + char dst_name[16]; /**< Destination address. */ + int dst_port; /**< Destination port. */ + } tp_info; }; @@ -397,6 +438,16 @@ PJ_DECL(pj_bool_t) pjsip_tx_data_is_valid( pjsip_tx_data *tdata ); */ PJ_DECL(void) pjsip_tx_data_invalidate_msg( pjsip_tx_data *tdata ); +/** + * Get short printable info about the transmit data. This will normally return + * short information about the message. + * + * @param tdata The transmit buffer. + * + * @return Null terminated info string. + */ +PJ_DECL(char*) pjsip_tx_data_get_info( pjsip_tx_data *tdata ); + /***************************************************************************** * @@ -593,16 +644,20 @@ PJ_DECL(pj_status_t) pjsip_tpmgr_unregister_tpfactory(pjsip_tpmgr *mgr, * * @param pool Pool. * @param endpt Endpoint instance. - * @param cb Callback to receive incoming message. + * @param rx_cb Callback to receive incoming message. + * @param tx_cb Callback to be called before transport manager is sending + * outgoing message. * @param p_mgr Pointer to receive the new transport manager. * * @return PJ_SUCCESS or the appropriate error code on error. */ PJ_DECL(pj_status_t) pjsip_tpmgr_create( pj_pool_t *pool, pjsip_endpoint * endpt, - void (*cb)(pjsip_endpoint*, - pj_status_t, - pjsip_rx_data *), + void (*rx_cb)(pjsip_endpoint*, + pj_status_t, + pjsip_rx_data *), + pj_status_t (*tx_cb)(pjsip_endpoint*, + pjsip_tx_data*), pjsip_tpmgr **p_mgr); diff --git a/pjsip/include/pjsip/sip_transport_loop.h b/pjsip/include/pjsip/sip_transport_loop.h index bfcb93f4..3cc2af86 100644 --- a/pjsip/include/pjsip/sip_transport_loop.h +++ b/pjsip/include/pjsip/sip_transport_loop.h @@ -58,9 +58,10 @@ PJ_DECL(pj_status_t) pjsip_loop_set_discard( pjsip_transport *tp, * will occur after some delay, which is controlled by #pjsip_loop_set_delay(). * * @param tp The loop transport. - * @param fail_flag If set to 1, the transport will return immediate error. - * If set to 2, the transport will return error via - * callback. If zero, the transport will deliver + * @param fail_flag If set to 1, the transport will return fail to deliver + * the message. If delay is zero, failure will occur + * immediately; otherwise it will be reported in callback. + * If set to zero, the transport will successfully deliver * the packet. * @param prev_value Optional argument to receive previous value of * the failure flag. @@ -73,7 +74,8 @@ PJ_DECL(pj_status_t) pjsip_loop_set_failure( pjsip_transport *tp, /** - * Set delay (in miliseconds) before packet is delivered. This will also + * Set delay (in miliseconds) before packet is received by the other end + * of the loop transport. This will also * control the delay for error notification callback. * * @param tp The loop transport. @@ -83,9 +85,38 @@ PJ_DECL(pj_status_t) pjsip_loop_set_failure( pjsip_transport *tp, * * @return PJ_SUCCESS on success. */ +PJ_DECL(pj_status_t) pjsip_loop_set_recv_delay( pjsip_transport *tp, + unsigned delay, + unsigned *prev_value); + + +/** + * Set delay (in miliseconds) before send notification is delivered to sender. + * This will also control the delay for error notification callback. + * + * @param tp The loop transport. + * @param delay Delay, in miliseconds. + * @param prev_value Optional argument to receive previous value of the + * delay. + * + * @return PJ_SUCCESS on success. + */ +PJ_DECL(pj_status_t) pjsip_loop_set_send_callback_delay( pjsip_transport *tp, + unsigned delay, + unsigned *prev_value); + + +/** + * Set both receive and send notification delay. + * + * @param tp The loop transport. + * @param delay Delay, in miliseconds. + * + * @return PJ_SUCCESS on success. + */ PJ_DECL(pj_status_t) pjsip_loop_set_delay( pjsip_transport *tp, - unsigned delay, - unsigned *prev_value); + unsigned delay ); + PJ_END_DECL diff --git a/pjsip/src/pjsip/sip_endpoint.c b/pjsip/src/pjsip/sip_endpoint.c index d299cfff..ea203415 100644 --- a/pjsip/src/pjsip/sip_endpoint.c +++ b/pjsip/src/pjsip/sip_endpoint.c @@ -35,7 +35,7 @@ #include <pj/lock.h> #define PJSIP_EX_NO_MEMORY PJ_NO_MEMORY_EXCEPTION -#define THIS_FILE "endpoint" +#define THIS_FILE "sip_endpoint.c" #define MAX_METHODS 32 @@ -98,8 +98,10 @@ struct pjsip_endpoint /* * Prototypes. */ -static void endpt_transport_callback(pjsip_endpoint*, - pj_status_t, pjsip_rx_data*); +static void endpt_on_rx_msg( pjsip_endpoint*, + pj_status_t, pjsip_rx_data*); +static pj_status_t endpt_on_tx_msg( pjsip_endpoint *endpt, + pjsip_tx_data *tdata ); /* Defined in sip_parser.c */ void init_sip_parser(void); @@ -229,6 +231,9 @@ PJ_DEF(pj_status_t) pjsip_endpt_unregister_module( pjsip_endpoint *endpt, /* Remove module from list. */ pj_list_erase(mod); + /* Set module Id to -1. */ + mod->id = -1; + /* Done. */ status = PJ_SUCCESS; @@ -312,7 +317,7 @@ PJ_DEF(pj_status_t) pjsip_endpt_create(pj_pool_factory *pf, pjsip_max_forwards_hdr *mf_hdr; pj_lock_t *lock = NULL; - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_create()")); + PJ_LOG(5, (THIS_FILE, "Creating endpoint instance...")); *p_endpt = NULL; @@ -382,7 +387,8 @@ PJ_DEF(pj_status_t) pjsip_endpt_create(pj_pool_factory *pf, /* Create transport manager. */ status = pjsip_tpmgr_create( endpt->pool, endpt, - &endpt_transport_callback, + &endpt_on_rx_msg, + &endpt_on_tx_msg, &endpt->transport_mgr); if (status != PJ_SUCCESS) { goto on_error; @@ -391,7 +397,7 @@ PJ_DEF(pj_status_t) pjsip_endpt_create(pj_pool_factory *pf, /* Create asynchronous DNS resolver. */ endpt->resolver = pjsip_resolver_create(endpt->pool); if (!endpt->resolver) { - PJ_LOG(4, (THIS_FILE, "pjsip_endpt_init(): error creating resolver")); + PJ_LOG(4, (THIS_FILE, "Error creating resolver instance")); goto on_error; } @@ -425,7 +431,7 @@ on_error: } pj_pool_release( endpt->pool ); - PJ_LOG(4, (THIS_FILE, "pjsip_endpt_init() failed")); + PJ_LOG(4, (THIS_FILE, "Error creating endpoint")); return status; } @@ -434,7 +440,14 @@ on_error: */ PJ_DEF(void) pjsip_endpt_destroy(pjsip_endpoint *endpt) { - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_destroy()")); + pjsip_module *mod; + + PJ_LOG(5, (THIS_FILE, "Destroying endpoing instance..")); + + /* Unregister modules. */ + while ((mod=endpt->module_list.prev) != &endpt->module_list) { + pjsip_endpt_unregister_module(endpt, mod); + } /* Shutdown and destroy all transports. */ pjsip_tpmgr_destroy(endpt->transport_mgr); @@ -444,6 +457,8 @@ PJ_DEF(void) pjsip_endpt_destroy(pjsip_endpoint *endpt) /* Finally destroy pool. */ pj_pool_release(endpt->pool); + + PJ_LOG(4, (THIS_FILE, "Endpoint %p destroyed", endpt)); } /* @@ -465,8 +480,6 @@ PJ_DEF(pj_pool_t*) pjsip_endpt_create_pool( pjsip_endpoint *endpt, { pj_pool_t *pool; - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_create_pool()")); - /* Lock endpoint mutex. */ pj_mutex_lock(endpt->mutex); @@ -477,9 +490,7 @@ PJ_DEF(pj_pool_t*) pjsip_endpt_create_pool( pjsip_endpoint *endpt, /* Unlock mutex. */ pj_mutex_unlock(endpt->mutex); - if (pool) { - PJ_LOG(5, (THIS_FILE, " pool %s created", pj_pool_getobjname(pool))); - } else { + if (!pool) { PJ_LOG(4, (THIS_FILE, "Unable to create pool %s!", pool_name)); } @@ -492,7 +503,7 @@ PJ_DEF(pj_pool_t*) pjsip_endpt_create_pool( pjsip_endpoint *endpt, */ PJ_DEF(void) pjsip_endpt_release_pool( pjsip_endpoint *endpt, pj_pool_t *pool ) { - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_release_pool(%s)", pj_pool_getobjname(pool))); + PJ_LOG(6, (THIS_FILE, "Releasing pool %s", pj_pool_getobjname(pool))); pj_mutex_lock(endpt->mutex); pj_pool_release( pool ); @@ -508,7 +519,7 @@ PJ_DEF(void) pjsip_endpt_handle_events( pjsip_endpoint *endpt, /* timeout is 'out' var. This just to make compiler happy. */ pj_time_val timeout = { 0, 0}; - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_handle_events()")); + PJ_LOG(6, (THIS_FILE, "pjsip_endpt_handle_events()")); /* Poll the timer. The timer heap has its own mutex for better * granularity, so we don't need to lock end endpoint. @@ -534,7 +545,7 @@ PJ_DEF(pj_status_t) pjsip_endpt_schedule_timer( pjsip_endpoint *endpt, pj_timer_entry *entry, const pj_time_val *delay ) { - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_schedule_timer(entry=%p, delay=%u.%u)", + PJ_LOG(6, (THIS_FILE, "pjsip_endpt_schedule_timer(entry=%p, delay=%u.%u)", entry, delay->sec, delay->msec)); return pj_timer_heap_schedule( endpt->timer_heap, entry, delay ); } @@ -545,7 +556,7 @@ PJ_DEF(pj_status_t) pjsip_endpt_schedule_timer( pjsip_endpoint *endpt, PJ_DEF(void) pjsip_endpt_cancel_timer( pjsip_endpoint *endpt, pj_timer_entry *entry ) { - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_cancel_timer(entry=%p)", entry)); + PJ_LOG(6, (THIS_FILE, "pjsip_endpt_cancel_timer(entry=%p)", entry)); pj_timer_heap_cancel( endpt->timer_heap, entry ); } @@ -553,14 +564,12 @@ PJ_DEF(void) pjsip_endpt_cancel_timer( pjsip_endpoint *endpt, * This is the callback that is called by the transport manager when it * receives a message from the network. */ -static void endpt_transport_callback( pjsip_endpoint *endpt, +static void endpt_on_rx_msg( pjsip_endpoint *endpt, pj_status_t status, pjsip_rx_data *rdata ) { pjsip_msg *msg = rdata->msg_info.msg; - PJ_LOG(5, (THIS_FILE, "endpt_transport_callback(rdata=%p)", rdata)); - if (status != PJ_SUCCESS) { PJSIP_ENDPT_LOG_ERROR((endpt, "transport", status, "Error processing packet from %s:%d, packet:--\n" @@ -572,6 +581,9 @@ static void endpt_transport_callback( pjsip_endpoint *endpt, return; } + PJ_LOG(5, (THIS_FILE, "Processing incoming message: %s", + pjsip_rx_data_get_info(rdata))); + /* For response, check that the value in Via sent-by match the transport. * If not matched, silently drop the response. * Ref: RFC3261 Section 18.1.2 Receiving Response @@ -600,17 +612,19 @@ static void endpt_transport_callback( pjsip_endpoint *endpt, rdata->tp_info.transport->local_name.port) mismatch = PJ_TRUE; else { - PJ_LOG(4,(THIS_FILE, "Response %p from %s has mismatch port in " + PJ_LOG(4,(THIS_FILE, "Message %s from %s has mismatch port in " "sent-by but the rport parameter is " "correct", - rdata, rdata->pkt_info.src_name)); + pjsip_rx_data_get_info(rdata), + rdata->pkt_info.src_name)); } } if (mismatch) { PJ_TODO(ENDPT_REPORT_WHEN_DROPPING_MESSAGE); - PJ_LOG(4,(THIS_FILE, "Dropping response from %s:%d because sent-by" - " is mismatch", + PJ_LOG(4,(THIS_FILE, "Dropping response %s from %s:%d because " + "sent-by is mismatch", + pjsip_rx_data_get_info(rdata), rdata->pkt_info.src_name, rdata->pkt_info.src_port)); return; @@ -618,7 +632,7 @@ static void endpt_transport_callback( pjsip_endpoint *endpt, } - /* Distribute to modules. */ + /* Distribute to modules, starting from modules with highest priority */ pj_rwmutex_lock_read(endpt->mod_mutex); if (msg->type == PJSIP_REQUEST_MSG) { @@ -637,8 +651,11 @@ static void endpt_transport_callback( pjsip_endpoint *endpt, /* No module is able to handle the request. */ if (!handled) { PJ_TODO(ENDPT_RESPOND_UNHANDLED_REQUEST); - PJ_LOG(4,(THIS_FILE, "Request from %s:%d was dropped/unhandled by" - " any modules")); + PJ_LOG(4,(THIS_FILE, "Message %s from %s:%d was dropped/unhandled by" + " any modules", + pjsip_rx_data_get_info(rdata), + rdata->pkt_info.src_name, + rdata->pkt_info.src_port)); } } else { @@ -655,21 +672,62 @@ static void endpt_transport_callback( pjsip_endpoint *endpt, } if (!handled) { - PJ_LOG(4,(THIS_FILE, "Response from %s:%d was dropped/unhandled by" - " any modules")); + PJ_LOG(4,(THIS_FILE, "Message %s from %s:%d was dropped/unhandled" + " by any modules", + pjsip_rx_data_get_info(rdata), + rdata->pkt_info.src_name, + rdata->pkt_info.src_port)); + } + } + + pj_rwmutex_unlock_read(endpt->mod_mutex); +} + +/* + * This callback is called by transport manager before message is sent. + * Modules may inspect the message before it's actually sent. + */ +static pj_status_t endpt_on_tx_msg( pjsip_endpoint *endpt, + pjsip_tx_data *tdata ) +{ + pj_status_t status = PJ_SUCCESS; + pjsip_module *mod; + + /* Distribute to modules, starting from modules with LOWEST priority */ + pj_rwmutex_lock_read(endpt->mod_mutex); + + mod = endpt->module_list.prev; + if (tdata->msg->type == PJSIP_REQUEST_MSG) { + while (mod != &endpt->module_list) { + if (mod->on_tx_request) + status = (*mod->on_tx_request)(tdata); + if (status != PJ_SUCCESS) + break; + mod = mod->prev; + } + + } else { + while (mod != &endpt->module_list) { + if (mod->on_tx_response) + status = (*mod->on_tx_response)(tdata); + if (status != PJ_SUCCESS) + break; + mod = mod->prev; } } pj_rwmutex_unlock_read(endpt->mod_mutex); + + return status; } + /* * Create transmit data buffer. */ PJ_DEF(pj_status_t) pjsip_endpt_create_tdata( pjsip_endpoint *endpt, pjsip_tx_data **p_tdata) { - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_create_tdata()")); return pjsip_tx_data_create(endpt->transport_mgr, p_tdata); } @@ -682,7 +740,6 @@ PJ_DEF(void) pjsip_endpt_resolve( pjsip_endpoint *endpt, void *token, pjsip_resolver_callback *cb) { - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_resolve()")); pjsip_resolve( endpt->resolver, pool, target, token, cb); } @@ -711,7 +768,6 @@ PJ_DEF(pj_status_t) pjsip_endpt_acquire_transport(pjsip_endpoint *endpt, int addr_len, pjsip_transport **transport) { - PJ_LOG(5, (THIS_FILE, "pjsip_endpt_acquire_transport()")); return pjsip_tpmgr_acquire_transport(endpt->transport_mgr, type, remote, addr_len, transport); } diff --git a/pjsip/src/pjsip/sip_errno.c b/pjsip/src/pjsip/sip_errno.c index f7d2ddd3..62de365a 100644 --- a/pjsip/src/pjsip/sip_errno.c +++ b/pjsip/src/pjsip/sip_errno.c @@ -33,6 +33,7 @@ static const struct /* Generic SIP errors */ { PJSIP_EBUSY, "Object is busy" }, { PJSIP_ETYPEEXISTS , "Object with the same type exists" }, + { PJSIP_ESHUTDOWN, "SIP stack shutting down" }, /* Messaging errors */ { PJSIP_EINVALIDMSG, "Invalid message/syntax error" }, diff --git a/pjsip/src/pjsip/sip_msg.c b/pjsip/src/pjsip/sip_msg.c index cee850eb..024744c2 100644 --- a/pjsip/src/pjsip/sip_msg.c +++ b/pjsip/src/pjsip/sip_msg.c @@ -117,6 +117,7 @@ static int init_status_phrase() pj_strset2( &status_phrase[183], "Session Progress"); pj_strset2( &status_phrase[200], "OK"); + pj_strset2( &status_phrase[202], "Accepted"); pj_strset2( &status_phrase[300], "Multiple Choices"); pj_strset2( &status_phrase[301], "Moved Permanently"); @@ -140,6 +141,7 @@ static int init_status_phrase() pj_strset2( &status_phrase[416], "Unsupported URI Scheme"); pj_strset2( &status_phrase[420], "Bad Extension"); pj_strset2( &status_phrase[421], "Extension Required"); + pj_strset2( &status_phrase[422], "Session Timer Too Small"); pj_strset2( &status_phrase[423], "Interval Too Brief"); pj_strset2( &status_phrase[480], "Temporarily Unavailable"); pj_strset2( &status_phrase[481], "Call/Transaction Does Not Exist"); @@ -150,6 +152,8 @@ static int init_status_phrase() pj_strset2( &status_phrase[486], "Busy Here"); pj_strset2( &status_phrase[487], "Request Terminated"); pj_strset2( &status_phrase[488], "Not Acceptable Here"); + pj_strset2( &status_phrase[489], "Unknown Event"); + pj_strset2( &status_phrase[490], "Request Updated"); pj_strset2( &status_phrase[491], "Request Pending"); pj_strset2( &status_phrase[493], "Undecipherable"); @@ -160,6 +164,7 @@ static int init_status_phrase() pj_strset2( &status_phrase[504], "Server Timeout"); pj_strset2( &status_phrase[505], "Version Not Supported"); pj_strset2( &status_phrase[513], "Message Too Large"); + pj_strset2( &status_phrase[580], "Precondition Failure"); pj_strset2( &status_phrase[600], "Busy Everywhere"); pj_strset2( &status_phrase[603], "Decline"); diff --git a/pjsip/src/pjsip/sip_resolve.c b/pjsip/src/pjsip/sip_resolve.c index 4be6f56c..4712b7f7 100644 --- a/pjsip/src/pjsip/sip_resolve.c +++ b/pjsip/src/pjsip/sip_resolve.c @@ -18,9 +18,13 @@ */ #include <pjsip/sip_resolve.h> #include <pjsip/sip_transport.h> +#include <pjsip/sip_errno.h> #include <pj/pool.h> #include <pj/ctype.h> #include <pj/assert.h> +#include <pj/log.h> + +#define THIS_FILE "sip_resolve.c" struct pjsip_resolver_t { @@ -68,6 +72,12 @@ PJ_DEF(void) pjsip_resolve( pjsip_resolver_t *resolver, PJ_UNUSED_ARG(resolver); PJ_UNUSED_ARG(pool); + PJ_LOG(5,(THIS_FILE, "Resolving server '%.*s:%d' type=%s", + target->addr.host.slen, + target->addr.host.ptr, + target->addr.port, + pjsip_transport_get_type_name(type))); + /* We only do synchronous resolving at this moment. */ PJ_TODO(SUPPORT_RFC3263_SERVER_RESOLUTION) @@ -116,10 +126,30 @@ PJ_DEF(void) pjsip_resolve( pjsip_resolver_t *resolver, status = pj_sockaddr_in_init((pj_sockaddr_in*)&svr_addr.entry[0].addr, &target->addr.host, (pj_uint16_t)target->addr.port); - pj_assert(status == PJ_SUCCESS); + } + + if (status != PJ_SUCCESS) { + char errmsg[PJSIP_ERR_MSG_SIZE]; + PJ_LOG(4,(THIS_FILE, "Failed to resolve '%.*s'. Err=%d (%s)", + target->addr.host.slen, + target->addr.host.ptr, + status, + pjsip_strerror(status,errmsg,sizeof(errmsg)).ptr)); + (*cb)(status, token, &svr_addr); + return; } /* Call the callback. */ + PJ_LOG(5,(THIS_FILE, "Server resolved: '%.*s:%d' type=%s has %d entries, " + "entry[0]=%s:%d type=%s", + target->addr.host.slen, + target->addr.host.ptr, + target->addr.port, + pjsip_transport_get_type_name(type), + 1, + pj_inet_ntoa(((pj_sockaddr_in*)&svr_addr.entry[0].addr)->sin_addr), + target->addr.port, + pjsip_transport_get_type_name(type))); svr_addr.count = (status == PJ_SUCCESS) ? 1 : 0; svr_addr.entry[0].type = type; svr_addr.entry[0].addr_len = sizeof(pj_sockaddr_in); diff --git a/pjsip/src/pjsip/sip_transaction.c b/pjsip/src/pjsip/sip_transaction.c index cd673338..885b5bb4 100644 --- a/pjsip/src/pjsip/sip_transaction.c +++ b/pjsip/src/pjsip/sip_transaction.c @@ -30,6 +30,8 @@ #include <pj/guid.h> #include <pj/log.h> +#define THIS_FILE "sip_transaction.c" + /***************************************************************************** ** ** Declarations and static variable definitions section. @@ -101,6 +103,7 @@ enum TSX_HAS_PENDING_RESCHED = 2, TSX_HAS_PENDING_SEND = 4, TSX_HAS_PENDING_DESTROY = 8, + TSX_HAS_RESOLVED_SERVER = 16, }; /* Transaction lock. */ @@ -412,6 +415,7 @@ PJ_DEF(pj_status_t) pjsip_tsx_layer_init(pjsip_endpoint *endpt) PJ_ASSERT_RETURN(mod_tsx_layer.endpt==NULL, PJ_EINVALIDOP); + PJ_LOG(5,(THIS_FILE, "Initializing transaction layer module")); /* Initialize TLS ID for transaction lock. */ status = pj_thread_local_alloc(&pjsip_tsx_lock_tls_id); @@ -461,6 +465,8 @@ PJ_DEF(pj_status_t) pjsip_tsx_layer_init(pjsip_endpoint *endpt) return status; } + PJ_LOG(4,(THIS_FILE, "Transaction layer module initialized")); + return PJ_SUCCESS; } @@ -580,15 +586,18 @@ static pj_status_t mod_tsx_layer_stop(void) { pj_hash_iterator_t it_buf, *it; + PJ_LOG(4,(THIS_FILE, "Stopping transaction layer module")); + pj_mutex_lock(mod_tsx_layer.mutex); /* Destroy all transactions. */ it = pj_hash_first(mod_tsx_layer.htable, &it_buf); while (it) { pjsip_transaction *tsx = pj_hash_this(mod_tsx_layer.htable, it); + pj_hash_iterator_t *next = pj_hash_next(mod_tsx_layer.htable, it); if (tsx) tsx_destroy(tsx); - it = pj_hash_next(mod_tsx_layer.htable, it); + it = next; } pj_mutex_unlock(mod_tsx_layer.mutex); @@ -610,6 +619,8 @@ static pj_status_t mod_tsx_layer_unload(void) /* Mark as unregistered. */ mod_tsx_layer.endpt = NULL; + PJ_LOG(4,(THIS_FILE, "Transaction layer module destroyed")); + return PJ_SUCCESS; } @@ -627,7 +638,9 @@ static pj_bool_t mod_tsx_layer_on_rx_request(pjsip_rx_data *rdata) /* Find transaction. */ pj_mutex_lock( mod_tsx_layer.mutex ); + tsx = pj_hash_get( mod_tsx_layer.htable, key.ptr, key.slen ); + if (tsx == NULL || tsx->state == PJSIP_TSX_STATE_TERMINATED) { /* Transaction not found. * Reject the request so that endpoint passes the request to @@ -666,7 +679,9 @@ static pj_bool_t mod_tsx_layer_on_rx_response(pjsip_rx_data *rdata) /* Find transaction. */ pj_mutex_lock( mod_tsx_layer.mutex ); + tsx = pj_hash_get( mod_tsx_layer.htable, key.ptr, key.slen ); + if (tsx == NULL || tsx->state == PJSIP_TSX_STATE_TERMINATED) { /* Transaction not found. * Reject the request so that endpoint passes the request to @@ -790,7 +805,53 @@ static pj_status_t tsx_create( pjsip_module *tsx_user, /* Destroy transaction. */ static void tsx_destroy( pjsip_transaction *tsx ) { + struct tsx_lock_data *lck; + + /* Decrement transport reference counter. */ + if (tsx->transport) { + pjsip_transport_dec_ref( tsx->transport ); + tsx->transport = NULL; + } + /* Free last transmitted message. */ + if (tsx->last_tx) { + pjsip_tx_data_dec_ref( tsx->last_tx ); + tsx->last_tx = NULL; + } + /* Cancel timeout timer. */ + if (tsx->timeout_timer._timer_id != -1) { + pjsip_endpt_cancel_timer(tsx->endpt, &tsx->timeout_timer); + tsx->timeout_timer._timer_id = -1; + } + /* Cancel retransmission timer. */ + if (tsx->retransmit_timer._timer_id != -1) { + pjsip_endpt_cancel_timer(tsx->endpt, &tsx->retransmit_timer); + tsx->retransmit_timer._timer_id = -1; + } + + /* Clear some pending flags. */ + tsx->transport_flag &= ~(TSX_HAS_PENDING_RESCHED | TSX_HAS_PENDING_SEND); + + /* Refuse to destroy transaction if it has pending resolving. */ + if (tsx->transport_flag & TSX_HAS_PENDING_TRANSPORT) { + tsx->transport_flag |= TSX_HAS_PENDING_DESTROY; + PJ_LOG(5,(tsx->obj_name, "Will destroy later because transport is " + "in progress")); + return; + } + + /* Clear TLS, so that mutex will not be unlocked */ + lck = pj_thread_local_get(pjsip_tsx_lock_tls_id); + while (lck) { + if (lck->tsx == tsx) { + lck->is_alive = 0; + } + lck = lck->prev; + } + pj_mutex_destroy(tsx->mutex); + + PJ_LOG(5,(tsx->obj_name, "Transaction destroyed!")); + pjsip_endpt_release_pool(tsx->endpt, tsx->pool); } @@ -806,7 +867,7 @@ static void tsx_timer_callback( pj_timer_heap_t *theap, pj_timer_entry *entry) PJ_UNUSED_ARG(theap); - PJ_LOG(5,(tsx->obj_name, "got timer event (%s timer)", + PJ_LOG(6,(tsx->obj_name, "%s timer event", (entry->id==TSX_TIMER_RETRANSMISSION ? "Retransmit":"Timeout"))); @@ -831,7 +892,7 @@ static void tsx_set_state( pjsip_transaction *tsx, pjsip_event_id_e event_src_type, void *event_src ) { - PJ_LOG(4, (tsx->obj_name, "STATE %s-->%s, cause = %s", + PJ_LOG(5, (tsx->obj_name, "State changed from %s to %s, event=%s", state_str[tsx->state], state_str[state], pjsip_event_str(event_src_type))); @@ -859,31 +920,16 @@ static void tsx_set_state( pjsip_transaction *tsx, if (state == PJSIP_TSX_STATE_TERMINATED) { pj_time_val timeout = {0, 0}; - /* Decrement transport reference counter. */ - if (tsx->transport) { - pjsip_transport_dec_ref( tsx->transport ); - tsx->transport = NULL; - } - /* Free last transmitted message. */ - if (tsx->last_tx) { - pjsip_tx_data_dec_ref( tsx->last_tx ); - tsx->last_tx = NULL; - } - /* Cancel timeout timer. */ - if (tsx->timeout_timer._timer_id != -1) { - pjsip_endpt_cancel_timer(tsx->endpt, &tsx->timeout_timer); - tsx->timeout_timer._timer_id = -1; - } - /* Cancel retransmission timer. */ - if (tsx->retransmit_timer._timer_id != -1) { - pjsip_endpt_cancel_timer(tsx->endpt, &tsx->retransmit_timer); - tsx->retransmit_timer._timer_id = -1; - } - /* Reschedule timeout timer to destroy this transaction. */ if (tsx->transport_flag & TSX_HAS_PENDING_TRANSPORT) { tsx->transport_flag |= TSX_HAS_PENDING_DESTROY; } else { + /* Cancel timeout timer. */ + if (tsx->timeout_timer._timer_id != -1) { + pjsip_endpt_cancel_timer(tsx->endpt, &tsx->timeout_timer); + tsx->timeout_timer._timer_id = -1; + } + pjsip_endpt_schedule_timer( tsx->endpt, &tsx->timeout_timer, &timeout); } @@ -891,15 +937,6 @@ static void tsx_set_state( pjsip_transaction *tsx, } else if (state == PJSIP_TSX_STATE_DESTROYED) { - /* Clear TLS, so that mutex will not be unlocked */ - struct tsx_lock_data *lck = pj_thread_local_get(pjsip_tsx_lock_tls_id); - while (lck) { - if (lck->tsx == tsx) { - lck->is_alive = 0; - } - lck = lck->prev; - } - /* Unregister transaction. */ mod_tsx_layer_unregister_tsx(tsx); @@ -920,6 +957,7 @@ PJ_DEF(pj_status_t) pjsip_tsx_create_uac( pjsip_module *tsx_user, pjsip_msg *msg; pjsip_cseq_hdr *cseq; pjsip_via_hdr *via; + pjsip_host_info dst_info; struct tsx_lock_data lck; pj_status_t status; @@ -998,6 +1036,15 @@ PJ_DEF(pj_status_t) pjsip_tsx_create_uac( pjsip_module *tsx_user, tsx->last_tx = tdata; pjsip_tx_data_add_ref(tsx->last_tx); + /* Determine whether reliable transport should be used initially. + * This will be updated whenever transport has changed. + */ + status = pjsip_get_request_addr(tdata, &dst_info); + if (status != PJ_SUCCESS) { + tsx_destroy(tsx); + return status; + } + tsx->is_reliable = (dst_info.flag & PJSIP_TRANSPORT_RELIABLE); /* Register transaction to hash table. */ mod_tsx_layer_register_tsx(tsx); @@ -1006,6 +1053,9 @@ PJ_DEF(pj_status_t) pjsip_tsx_create_uac( pjsip_module *tsx_user, /* Unlock transaction and return. */ unlock_tsx(tsx, &lck); + PJ_LOG(5,(tsx->obj_name, "Transaction created for %s", + pjsip_tx_data_get_info(tdata))); + *p_tsx = tsx; return PJ_SUCCESS; } @@ -1112,6 +1162,11 @@ PJ_DEF(pj_status_t) pjsip_tsx_create_uas( pjsip_module *tsx_user, /* Unlock transaction and return. */ unlock_tsx(tsx, &lck); + + PJ_LOG(5,(tsx->obj_name, "Transaction created for %s", + pjsip_rx_data_get_info(rdata))); + + *p_tsx = tsx; return PJ_SUCCESS; } @@ -1127,6 +1182,9 @@ PJ_DEF(pj_status_t) pjsip_tsx_terminate( pjsip_transaction *tsx, int code ) PJ_ASSERT_RETURN(tsx != NULL, PJ_EINVAL); PJ_ASSERT_RETURN(code >= 200, PJ_EINVAL); + if (tsx->state == PJSIP_TSX_STATE_TERMINATED) + return PJ_SUCCESS; + lock_tsx(tsx, &lck); tsx->status_code = code; tsx_set_state( tsx, PJSIP_TSX_STATE_TERMINATED, PJSIP_EVENT_USER, NULL); @@ -1151,8 +1209,9 @@ PJ_DEF(pj_status_t) pjsip_tsx_send_msg( pjsip_transaction *tsx, PJ_ASSERT_RETURN(tdata != NULL, PJ_EINVALIDOP); - PJ_LOG(5,(tsx->obj_name, "Request to transmit msg on state %s (tdata=%p)", - state_str[tsx->state], tdata)); + PJ_LOG(5,(tsx->obj_name, "Sending %s in state %s", + pjsip_tx_data_get_info(tdata), + state_str[tsx->state])); PJSIP_EVENT_INIT_TX_MSG(event, tsx, tdata); @@ -1161,6 +1220,11 @@ PJ_DEF(pj_status_t) pjsip_tsx_send_msg( pjsip_transaction *tsx, status = (*tsx->state_handler)(tsx, &event); unlock_tsx(tsx, &lck); + /* Will always decrement tdata reference counter + * (consistent with other send functions. + */ + pjsip_tx_data_dec_ref(tdata); + return status; } @@ -1175,8 +1239,8 @@ static void tsx_on_rx_msg( pjsip_transaction *tsx, pjsip_rx_data *rdata) struct tsx_lock_data lck; pj_status_t status; - PJ_LOG(5,(tsx->obj_name, "Incoming msg on state %s (rdata=%p)", - state_str[tsx->state], rdata)); + PJ_LOG(5,(tsx->obj_name, "Incoming %s in state %s", + pjsip_rx_data_get_info(rdata), state_str[tsx->state])); /* Put the transaction in the rdata's mod_data. */ rdata->endpt_info.mod_data[mod_tsx_layer.mod.id] = tsx; @@ -1205,17 +1269,30 @@ static void send_msg_callback( pjsip_send_state *send_state, pj_assert(send_state->cur_transport != NULL); if (tsx->transport != send_state->cur_transport) { + /* Update transport. */ if (tsx->transport) { pjsip_transport_dec_ref(tsx->transport); tsx->transport = NULL; } tsx->transport = send_state->cur_transport; pjsip_transport_add_ref(tsx->transport); + + /* Update remote address. */ + tsx->addr_len = send_state->addr.entry[send_state->cur_addr].addr_len; + pj_memcpy(&tsx->addr, + &send_state->addr.entry[send_state->cur_addr].addr, + tsx->addr_len); + + /* Update is_reliable flag. */ + tsx->is_reliable = PJSIP_TRANSPORT_IS_RELIABLE(tsx->transport); } /* Clear pending transport flag. */ tsx->transport_flag &= ~(TSX_HAS_PENDING_TRANSPORT); + /* Mark that we have resolved the addresses. */ + tsx->transport_flag |= TSX_HAS_RESOLVED_SERVER; + /* Pending destroy? */ if (tsx->transport_flag & TSX_HAS_PENDING_DESTROY) { tsx_set_state( tsx, PJSIP_TSX_STATE_DESTROYED, @@ -1233,7 +1310,11 @@ static void send_msg_callback( pjsip_send_state *send_state, /* Need to reschedule retransmission? */ if (tsx->transport_flag & TSX_HAS_PENDING_RESCHED) { tsx->transport_flag &= ~(TSX_HAS_PENDING_RESCHED); - tsx_resched_retransmission(tsx); + + /* Only update when transport turns out to be unreliable. */ + if (!tsx->is_reliable) { + tsx_resched_retransmission(tsx); + } } } else { @@ -1251,16 +1332,36 @@ static void send_msg_callback( pjsip_send_state *send_state, } if (!*cont) { - PJ_LOG(4,(tsx->obj_name, "Failed to send message! status=%d", - -sent)); + char errmsg[PJSIP_ERR_MSG_SIZE]; + + PJ_LOG(4,(tsx->obj_name, + "Failed to send %s! err=%d (%s)", + pjsip_tx_data_get_info(send_state->tdata), -sent, + pjsip_strerror(-sent, errmsg, sizeof(errmsg)).ptr)); /* Clear pending transport flag. */ tsx->transport_flag &= ~(TSX_HAS_PENDING_TRANSPORT); - /* Terminate transaction. */ + /* Mark that we have resolved the addresses. */ + tsx->transport_flag |= TSX_HAS_RESOLVED_SERVER; + + /* Terminate transaction, if it's not already terminated. */ tsx->status_code = PJSIP_SC_TSX_TRANSPORT_ERROR; - tsx_set_state( tsx, PJSIP_TSX_STATE_TERMINATED, - PJSIP_EVENT_TRANSPORT_ERROR, send_state->tdata ); + if (tsx->state != PJSIP_TSX_STATE_TERMINATED && + tsx->state != PJSIP_TSX_STATE_DESTROYED) + { + tsx_set_state( tsx, PJSIP_TSX_STATE_TERMINATED, + PJSIP_EVENT_TRANSPORT_ERROR, send_state->tdata); + } + + } else { + char errmsg[PJSIP_ERR_MSG_SIZE]; + + PJ_LOG(4,(tsx->obj_name, + "Temporary failure in sending %s, " + "will try next server. Err=%d (%s)", + pjsip_tx_data_get_info(send_state->tdata), -sent, + pjsip_strerror(-sent, errmsg, sizeof(errmsg)).ptr)); } } @@ -1275,9 +1376,11 @@ static void transport_callback(void *token, pjsip_tx_data *tdata, if (sent < 0) { pjsip_transaction *tsx = token; struct tsx_lock_data lck; + char errmsg[PJSIP_ERR_MSG_SIZE]; - PJ_LOG(4,(tsx->obj_name, "Failed to send message! status=%d", - -sent)); + PJ_LOG(4,(tsx->obj_name, "Transport failed to send %s! Err=%d (%s)", + pjsip_tx_data_get_info(tdata), -sent, + pjsip_strerror(-sent, errmsg, sizeof(errmsg)).ptr)); lock_tsx(tsx, &lck); @@ -1300,7 +1403,7 @@ static void transport_callback(void *token, pjsip_tx_data *tdata, static pj_status_t tsx_send_msg( pjsip_transaction *tsx, pjsip_tx_data *tdata) { - pj_status_t status = PJ_EBUG; + pj_status_t status = PJ_SUCCESS; PJ_ASSERT_RETURN(tsx && tdata, PJ_EINVAL); @@ -1310,70 +1413,112 @@ static pj_status_t tsx_send_msg( pjsip_transaction *tsx, return PJ_SUCCESS; } - if (tdata->msg->type == PJSIP_REQUEST_MSG) { - /* If we have the transport, send the message using that transport. - * Otherwise perform full transport resolution. - */ - if (tsx->transport) { - status = pjsip_transport_send( tsx->transport, tdata, &tsx->addr, - tsx->addr_len, tsx, - &transport_callback); - if (status == PJ_EPENDING) - status = PJ_SUCCESS; + /* If we have the transport, send the message using that transport. + * Otherwise perform full transport resolution. + */ + if (tsx->transport) { + status = pjsip_transport_send( tsx->transport, tdata, &tsx->addr, + tsx->addr_len, tsx, + &transport_callback); + if (status == PJ_EPENDING) + status = PJ_SUCCESS; - if (status != PJ_SUCCESS) { - /* On error, release transport to force using full transport - * resolution procedure. - */ - if (tsx->transport) { - pjsip_transport_dec_ref(tsx->transport); - tsx->transport = NULL; - } - tsx->addr_len = 0; + if (status != PJ_SUCCESS) { + char errmsg[PJSIP_ERR_MSG_SIZE]; + + PJ_LOG(4,(tsx->obj_name, + "Error sending %s: Err=%d (%s)", + pjsip_tx_data_get_info(tdata), status, + pjsip_strerror(status, errmsg, sizeof(errmsg)).ptr)); + + /* On error, release transport to force using full transport + * resolution procedure. + */ + if (tsx->transport) { + pjsip_transport_dec_ref(tsx->transport); + tsx->transport = NULL; } + tsx->addr_len = 0; + tsx->res_addr.transport = NULL; + tsx->res_addr.addr_len = 0; + } else { + return PJ_SUCCESS; } + } + + /* We are here because we don't have transport, or we failed to send + * the message using existing transport. If we haven't resolved the + * server before, then begin the long process of resolving the server + * and send the message with possibly new server. + */ + pj_assert(status != PJ_SUCCESS || tsx->transport == NULL); + + /* If we have resolved the server, we treat the error as permanent error. + * Terminate transaction with transport error failure. + */ + if (tsx->transport_flag & TSX_HAS_RESOLVED_SERVER) { - if (!tsx->transport) { - tsx->transport_flag |= TSX_HAS_PENDING_TRANSPORT; - status = pjsip_endpt_send_request_stateless(tsx->endpt, tdata, tsx, - &send_msg_callback); - if (status == PJ_EPENDING) - status = PJ_SUCCESS; + char errmsg[PJSIP_ERR_MSG_SIZE]; + + if (status == PJ_SUCCESS) { + pj_assert(!"Unexpected status!"); + status = PJ_EUNKNOWN; } - } else { - /* If we have the transport, send the message using that transport. - * Otherwise perform full transport resolution. + /* We have resolved the server!. + * Treat this as permanent transport error. */ - if (tsx->transport) { - status = pjsip_transport_send( tsx->transport, tdata, - &tsx->addr, tsx->addr_len, - tsx, &transport_callback); - if (status == PJ_EPENDING) - status = PJ_SUCCESS; + PJ_LOG(4,(tsx->obj_name, + "Transport error, terminating transaction. " + "Err=%d (%s)", + status, + pjsip_strerror(status, errmsg, sizeof(errmsg)).ptr)); - if (status != PJ_SUCCESS) { - if (tsx->transport) { - pjsip_transport_dec_ref(tsx->transport); - tsx->transport = NULL; - } - tsx->addr_len = 0; - tsx->res_addr.transport = NULL; - tsx->res_addr.addr_len = 0; - } + tsx->status_code = PJSIP_SC_TSX_TRANSPORT_ERROR; + tsx_set_state( tsx, PJSIP_TSX_STATE_TERMINATED, + PJSIP_EVENT_TRANSPORT_ERROR, NULL ); - } + return status; + } + + /* Must add reference counter because the send request functions + * decrement the reference counter. + */ + pjsip_tx_data_add_ref(tdata); + + /* Begin resolving destination etc to send the message. */ + if (tdata->msg->type == PJSIP_REQUEST_MSG) { + + tsx->transport_flag |= TSX_HAS_PENDING_TRANSPORT; + status = pjsip_endpt_send_request_stateless(tsx->endpt, tdata, tsx, + &send_msg_callback); + if (status == PJ_EPENDING) + status = PJ_SUCCESS; + if (status != PJ_SUCCESS) + pjsip_tx_data_dec_ref(tdata); + + /* Check if transaction is terminated. */ + if (status==PJ_SUCCESS && tsx->state == PJSIP_TSX_STATE_TERMINATED) + status = PJSIP_ETSXDESTROYED; + + } else { + + tsx->transport_flag |= TSX_HAS_PENDING_TRANSPORT; + status = pjsip_endpt_send_response( tsx->endpt, &tsx->res_addr, + tdata, tsx, + &send_msg_callback); + if (status == PJ_EPENDING) + status = PJ_SUCCESS; + if (status != PJ_SUCCESS) + pjsip_tx_data_dec_ref(tdata); + + /* Check if transaction is terminated. */ + if (status==PJ_SUCCESS && tsx->state == PJSIP_TSX_STATE_TERMINATED) + status = PJSIP_ETSXDESTROYED; - if (!tsx->transport) { - tsx->transport_flag |= TSX_HAS_PENDING_TRANSPORT; - status = pjsip_endpt_send_response( tsx->endpt, &tsx->res_addr, - tdata, tsx, - &send_msg_callback); - if (status == PJ_EPENDING) - status = PJ_SUCCESS; - } } + return status; } @@ -1408,8 +1553,9 @@ static pj_status_t tsx_retransmit( pjsip_transaction *tsx, int resched) PJ_ASSERT_RETURN(tsx->last_tx!=NULL, PJ_EBUG); - PJ_LOG(4,(tsx->obj_name, "retransmiting (tdata=%p, count=%d, restart?=%d)", - tsx->last_tx, tsx->retransmit_count, resched)); + PJ_LOG(5,(tsx->obj_name, "Retransmiting %s, count=%d, restart?=%d", + pjsip_tx_data_get_info(tsx->last_tx), + tsx->retransmit_count, resched)); ++tsx->retransmit_count; @@ -1451,7 +1597,11 @@ static pj_status_t tsx_on_state_null( pjsip_transaction *tsx, } else { pjsip_tx_data *tdata; - /* Must be transmit event. */ + /* Must be transmit event. + * You may got this assertion when using loop transport with delay + * set to zero. That would cause on_rx_response() callback to be + * called before tsx_send_msg() has completed. + */ PJ_ASSERT_RETURN(event->type == PJSIP_EVENT_TX_MSG, PJ_EBUG); /* Get the txdata */ @@ -1482,7 +1632,7 @@ static pj_status_t tsx_on_state_null( pjsip_transaction *tsx, /* Start Timer A (or timer E) for retransmission only if unreliable * transport is being used. */ - if (!PJSIP_TRANSPORT_IS_RELIABLE(tsx->transport)) { + if (!tsx->is_reliable) { tsx->retransmit_count = 0; if (tsx->transport_flag & TSX_HAS_PENDING_TRANSPORT) { tsx->transport_flag |= TSX_HAS_PENDING_RESCHED; @@ -1527,9 +1677,11 @@ static pj_status_t tsx_on_state_calling( pjsip_transaction *tsx, { /* Cancel retransmission timer. */ - if (PJSIP_TRANSPORT_IS_RELIABLE(tsx->transport)==0) { + if (tsx->retransmit_timer._timer_id != -1) { pjsip_endpt_cancel_timer(tsx->endpt, &tsx->retransmit_timer); + tsx->retransmit_timer._timer_id = -1; } + tsx->transport_flag &= ~(TSX_HAS_PENDING_RESCHED); /* Set status code */ tsx->status_code = PJSIP_SC_TSX_TIMEOUT; @@ -1553,8 +1705,12 @@ static pj_status_t tsx_on_state_calling( pjsip_transaction *tsx, return PJSIP_ENOTRESPONSEMSG; /* Cancel retransmission timer A. */ - if (PJSIP_TRANSPORT_IS_RELIABLE(tsx->transport)==0) + if (tsx->retransmit_timer._timer_id != -1) { pjsip_endpt_cancel_timer(tsx->endpt, &tsx->retransmit_timer); + tsx->retransmit_timer._timer_id = -1; + } + tsx->transport_flag &= ~(TSX_HAS_PENDING_RESCHED); + /* Cancel timer B (transaction timeout) */ pjsip_endpt_cancel_timer(tsx->endpt, &tsx->timeout_timer); @@ -1738,7 +1894,7 @@ static pj_status_t tsx_on_state_proceeding_uas( pjsip_transaction *tsx, /* Start timer J at 64*T1 for unreliable transport or zero for * reliable transport. */ - if (!PJSIP_TRANSPORT_IS_RELIABLE(tsx->transport)) { + if (!tsx->is_reliable) { timeout = timeout_timer_val; } else { timeout.sec = timeout.msec = 0; @@ -1769,7 +1925,7 @@ static pj_status_t tsx_on_state_proceeding_uas( pjsip_transaction *tsx, /* For INVITE, if unreliable transport is used, retransmission * timer G will be scheduled (retransmission). */ - if (!PJSIP_TRANSPORT_IS_RELIABLE(tsx->transport)) { + if (!tsx->is_reliable) { pjsip_cseq_hdr *cseq = pjsip_msg_find_hdr( msg, PJSIP_H_CSEQ, NULL); if (cseq->method.id == PJSIP_INVITE_METHOD) { @@ -1893,7 +2049,7 @@ static pj_status_t tsx_on_state_proceeding_uac(pjsip_transaction *tsx, /* For unreliable transport, start timer D (for INVITE) or * timer K for non-INVITE. */ - if (PJSIP_TRANSPORT_IS_RELIABLE(tsx->transport) == 0) { + if (!tsx->is_reliable) { if (tsx->method.id == PJSIP_INVITE_METHOD) { timeout = td_timer_val; } else { @@ -1939,7 +2095,7 @@ static pj_status_t tsx_on_state_proceeding_uac(pjsip_transaction *tsx, } /* Start Timer D with TD/T4 timer if unreliable transport is used. */ - if (!PJSIP_TRANSPORT_IS_RELIABLE(tsx->transport)) { + if (!tsx->is_reliable) { if (tsx->method.id == PJSIP_INVITE_METHOD) { timeout = td_timer_val; } else { @@ -1992,7 +2148,11 @@ static pj_status_t tsx_on_state_completed_uas( pjsip_transaction *tsx, /* Process incoming ACK request. */ /* Cease retransmission. */ - pjsip_endpt_cancel_timer( tsx->endpt, &tsx->retransmit_timer ); + if (tsx->retransmit_timer._timer_id != -1) { + pjsip_endpt_cancel_timer(tsx->endpt, &tsx->retransmit_timer); + tsx->retransmit_timer._timer_id = -1; + } + tsx->transport_flag &= ~(TSX_HAS_PENDING_RESCHED); /* Start timer I in T4 interval (transaction termination). */ pjsip_endpt_cancel_timer( tsx->endpt, &tsx->timeout_timer ); diff --git a/pjsip/src/pjsip/sip_transport.c b/pjsip/src/pjsip/sip_transport.c index 4823feb9..742cf9e1 100644 --- a/pjsip/src/pjsip/sip_transport.c +++ b/pjsip/src/pjsip/sip_transport.c @@ -22,6 +22,7 @@ #include <pjsip/sip_msg.h> #include <pjsip/sip_private.h> #include <pjsip/sip_errno.h> +#include <pjsip/sip_module.h> #include <pj/os.h> #include <pj/log.h> #include <pj/ioqueue.h> @@ -32,7 +33,33 @@ #include <pj/lock.h> -#define THIS_FILE "transport" +#define THIS_FILE "sip_transport.c" + +/* Prototype. */ +static pj_status_t mod_on_tx_msg(pjsip_tx_data *tdata); + +/* This module has sole purpose to print transmit data to contigous buffer + * before actually transmitted to the wire. + */ +static pjsip_module mod_msg_print = +{ + NULL, NULL, /* prev and next */ + { "mod-msg-print", 13}, /* Name. */ + -1, /* Id */ + PJSIP_MOD_PRIORITY_TRANSPORT_LAYER, /* Priority */ + NULL, /* User data. */ + 0, /* Number of methods supported (=0). */ + { 0 }, /* Array of methods (none) */ + NULL, /* load() */ + NULL, /* start() */ + NULL, /* stop() */ + NULL, /* unload() */ + NULL, /* on_rx_request() */ + NULL, /* on_rx_response() */ + &mod_on_tx_msg, /* on_tx_request() */ + &mod_on_tx_msg, /* on_tx_response() */ + NULL, /* on_tsx_state() */ +}; /* * Transport manager. @@ -46,7 +73,8 @@ struct pjsip_tpmgr #if defined(PJ_DEBUG) && PJ_DEBUG!=0 pj_atomic_t *tdata_counter; #endif - void (*msg_cb)(pjsip_endpoint*, pj_status_t, pjsip_rx_data*); + void (*on_rx_msg)(pjsip_endpoint*, pj_status_t, pjsip_rx_data*); + pj_status_t (*on_tx_msg)(pjsip_endpoint*, pjsip_tx_data*); }; /***************************************************************************** @@ -66,7 +94,7 @@ const struct unsigned flag; } transport_names[] = { - { PJSIP_TRANSPORT_UNSPECIFIED, 0, {NULL, 0}, 0}, + { PJSIP_TRANSPORT_UNSPECIFIED, 0, {"Unspecified", 11}, 0}, { PJSIP_TRANSPORT_UDP, 5060, {"UDP", 3}, PJSIP_TRANSPORT_DATAGRAM}, { PJSIP_TRANSPORT_TCP, 5060, {"TCP", 3}, PJSIP_TRANSPORT_RELIABLE}, { PJSIP_TRANSPORT_TLS, 5061, {"TLS", 3}, PJSIP_TRANSPORT_RELIABLE | PJSIP_TRANSPORT_SECURE}, @@ -90,6 +118,9 @@ pjsip_transport_get_type_from_name(const pj_str_t *name) PJ_ASSERT_RETURN(transport_names[PJSIP_TRANSPORT_UDP].type == PJSIP_TRANSPORT_UDP, PJSIP_TRANSPORT_UNSPECIFIED); + if (name->slen == 0) + return PJSIP_TRANSPORT_UNSPECIFIED; + /* Get transport type from name. */ for (i=0; i<PJ_ARRAY_SIZE(transport_names); ++i) { if (pj_stricmp(name, &transport_names[i].name) == 0) { @@ -162,6 +193,23 @@ pjsip_transport_get_default_port_for_type(pjsip_transport_type_e type) return transport_names[type].port; } +/* + * Get transport name. + */ +PJ_DEF(const char*) pjsip_transport_get_type_name(pjsip_transport_type_e type) +{ + /* Sanity check. + * Check that transport_names[] are indexed on transport type. + */ + PJ_ASSERT_RETURN(transport_names[PJSIP_TRANSPORT_UDP].type == + PJSIP_TRANSPORT_UDP, "Unknown"); + + /* Check that argument is valid. */ + PJ_ASSERT_RETURN(type < PJ_ARRAY_SIZE(transport_names), "Unknown"); + + /* Return the port. */ + return transport_names[type].name.ptr; +} /***************************************************************************** * @@ -181,8 +229,6 @@ PJ_DEF(pj_status_t) pjsip_tx_data_create( pjsip_tpmgr *mgr, PJ_ASSERT_RETURN(mgr && p_tdata, PJ_EINVAL); - PJ_LOG(5, ("", "pjsip_tx_data_create")); - pool = pjsip_endpt_create_pool( mgr->endpt, "tdta%p", PJSIP_POOL_LEN_TDATA, PJSIP_POOL_INC_TDATA ); @@ -234,7 +280,8 @@ PJ_DEF(pj_status_t) pjsip_tx_data_dec_ref( pjsip_tx_data *tdata ) { pj_assert( pj_atomic_get(tdata->ref_cnt) > 0); if (pj_atomic_dec_and_get(tdata->ref_cnt) <= 0) { - PJ_LOG(5,(tdata->obj_name, "destroying txdata")); + PJ_LOG(5,(tdata->obj_name, "Destroying txdata %s", + pjsip_tx_data_get_info(tdata))); #if defined(PJ_DEBUG) && PJ_DEBUG!=0 pj_atomic_dec( tdata->mgr->tdata_counter ); #endif @@ -254,6 +301,7 @@ PJ_DEF(pj_status_t) pjsip_tx_data_dec_ref( pjsip_tx_data *tdata ) PJ_DEF(void) pjsip_tx_data_invalidate_msg( pjsip_tx_data *tdata ) { tdata->buf.cur = tdata->buf.start; + tdata->info = NULL; } PJ_DEF(pj_bool_t) pjsip_tx_data_is_valid( pjsip_tx_data *tdata ) @@ -261,7 +309,72 @@ PJ_DEF(pj_bool_t) pjsip_tx_data_is_valid( pjsip_tx_data *tdata ) return tdata->buf.cur != tdata->buf.start; } +static char *get_msg_info(pj_pool_t *pool, const char *obj_name, + const pjsip_msg *msg) +{ + char info_buf[128], *info; + const pjsip_cseq_hdr *cseq; + int len; + + cseq = pjsip_msg_find_hdr(msg, PJSIP_H_CSEQ, NULL); + PJ_ASSERT_RETURN(cseq != NULL, "INVALID MSG"); + + if (msg->type == PJSIP_REQUEST_MSG) { + len = pj_snprintf(info_buf, sizeof(info_buf), + "Request msg %.*s/cseq=%d (%s)", + msg->line.req.method.name.slen, + msg->line.req.method.name.ptr, + cseq->cseq, obj_name); + } else { + len = pj_snprintf(info_buf, sizeof(info_buf), + "Response msg %d/%.*s/cseq=%d (%s)", + msg->line.status.code, + cseq->method.name.slen, + cseq->method.name.ptr, + cseq->cseq, obj_name); + } + + if (len < 1 || len >= sizeof(info_buf)) { + return (char*)obj_name; + } + + info = pj_pool_alloc(pool, len+1); + pj_memcpy(info, info_buf, len+1); + + return info; +} + +PJ_DEF(char*) pjsip_tx_data_get_info( pjsip_tx_data *tdata ) +{ + + PJ_ASSERT_RETURN(tdata && tdata->msg, "INVALID MSG"); + + if (tdata->info) + return tdata->info; + + pj_lock_acquire(tdata->lock); + tdata->info = get_msg_info(tdata->pool, tdata->obj_name, tdata->msg); + pj_lock_release(tdata->lock); + + return tdata->info; +} + +PJ_DEF(char*) pjsip_rx_data_get_info(pjsip_rx_data *rdata) +{ + char obj_name[16]; + + PJ_ASSERT_RETURN(rdata->msg_info.msg, "INVALID MSG"); + + if (rdata->msg_info.info) + return rdata->msg_info.info; + pj_native_strcpy(obj_name, "rdata"); + pj_sprintf(obj_name+5, "%p", rdata); + + rdata->msg_info.info = get_msg_info(rdata->tp_info.pool, obj_name, + rdata->msg_info.msg); + return rdata->msg_info.info; +} /***************************************************************************** * @@ -298,6 +411,35 @@ static void transport_send_callback(pjsip_transport *transport, pjsip_tx_data_dec_ref(tdata); } +/* This function is called by endpoint for on_tx_request() and on_tx_response() + * notification. + */ +static pj_status_t mod_on_tx_msg(pjsip_tx_data *tdata) +{ + /* Allocate buffer if necessary. */ + if (tdata->buf.start == NULL) { + tdata->buf.start = pj_pool_alloc( tdata->pool, PJSIP_MAX_PKT_LEN); + tdata->buf.cur = tdata->buf.start; + tdata->buf.end = tdata->buf.start + PJSIP_MAX_PKT_LEN; + } + + /* Do we need to reprint? */ + if (!pjsip_tx_data_is_valid(tdata)) { + pj_ssize_t size; + + size = pjsip_msg_print( tdata->msg, tdata->buf.start, + tdata->buf.end - tdata->buf.start); + if (size < 0) { + return PJSIP_EMSGTOOLONG; + } + pj_assert(size != 0); + tdata->buf.cur += size; + tdata->buf.cur[size] = '\0'; + } + + return PJ_SUCCESS; +} + /* * Send a SIP message using the specified transport. */ @@ -320,25 +462,28 @@ PJ_DEF(pj_status_t) pjsip_transport_send( pjsip_transport *tr, return PJSIP_EPENDINGTX; } - /* Allocate buffer if necessary. */ - if (tdata->buf.start == NULL) { - tdata->buf.start = pj_pool_alloc( tdata->pool, PJSIP_MAX_PKT_LEN); - tdata->buf.cur = tdata->buf.start; - tdata->buf.end = tdata->buf.start + PJSIP_MAX_PKT_LEN; + /* Fill in tp_info. */ + tdata->tp_info.transport = tr; + pj_memcpy(&tdata->tp_info.dst_addr, addr, addr_len); + tdata->tp_info.dst_addr_len = addr_len; + if (addr->sa_family == PJ_AF_INET) { + const char *str_addr; + str_addr = pj_inet_ntoa(((pj_sockaddr_in*)addr)->sin_addr); + pj_native_strcpy(tdata->tp_info.dst_name, str_addr); + tdata->tp_info.dst_port = pj_ntohs(((pj_sockaddr_in*)addr)->sin_port); + } else { + pj_native_strcpy(tdata->tp_info.dst_name, "<unknown>"); + tdata->tp_info.dst_port = 0; } - /* Do we need to reprint? */ - if (!pjsip_tx_data_is_valid(tdata)) { - pj_ssize_t size; - - size = pjsip_msg_print( tdata->msg, tdata->buf.start, - tdata->buf.end - tdata->buf.start); - if (size < 0) { - return PJSIP_EMSGTOOLONG; - } - pj_assert(size != 0); - tdata->buf.cur += size; - tdata->buf.cur[size] = '\0'; + /* Distribute to modules. + * When the message reach mod_msg_print, the contents of the message will + * be "printed" to contiguous buffer. + */ + if (tr->tpmgr->on_tx_msg) { + status = (*tr->tpmgr->on_tx_msg)(tr->endpt, tdata); + if (status != PJ_SUCCESS) + return status; } /* Save callback data. */ @@ -449,18 +594,12 @@ PJ_DEF(pj_status_t) pjsip_transport_register( pjsip_tpmgr *mgr, return PJ_SUCCESS; } - -/** - * Unregister transport. - */ -PJ_DEF(pj_status_t) pjsip_transport_unregister( pjsip_tpmgr *mgr, - pjsip_transport *tp) +/* Force destroy transport (e.g. during transport manager shutdown. */ +static pj_status_t destroy_transport( pjsip_tpmgr *mgr, + pjsip_transport *tp ) { int key_len; - /* Must have no user. */ - PJ_ASSERT_RETURN(pj_atomic_get(tp->ref_cnt) == 0, PJSIP_EBUSY); - pj_lock_acquire(tp->lock); pj_lock_acquire(mgr->lock); @@ -485,6 +624,19 @@ PJ_DEF(pj_status_t) pjsip_transport_unregister( pjsip_tpmgr *mgr, return tp->destroy(tp); } +/** + * Unregister transport. + */ +PJ_DEF(pj_status_t) pjsip_transport_unregister( pjsip_tpmgr *mgr, + pjsip_transport *tp) +{ + /* Must have no user. */ + PJ_ASSERT_RETURN(pj_atomic_get(tp->ref_cnt) == 0, PJSIP_EBUSY); + + /* Destroy. */ + return destroy_transport(mgr, tp); +} + /***************************************************************************** @@ -556,21 +708,28 @@ PJ_DEF(pj_status_t) pjsip_tpmgr_unregister_tpfactory( pjsip_tpmgr *mgr, */ PJ_DEF(pj_status_t) pjsip_tpmgr_create( pj_pool_t *pool, pjsip_endpoint *endpt, - void (*cb)(pjsip_endpoint*, - pj_status_t, - pjsip_rx_data *), + void (*rx_cb)(pjsip_endpoint*, + pj_status_t, + pjsip_rx_data *), + pj_status_t (*tx_cb)(pjsip_endpoint*, + pjsip_tx_data*), pjsip_tpmgr **p_mgr) { pjsip_tpmgr *mgr; pj_status_t status; - PJ_ASSERT_RETURN(pool && endpt && cb && p_mgr, PJ_EINVAL); + PJ_ASSERT_RETURN(pool && endpt && rx_cb && p_mgr, PJ_EINVAL); - PJ_LOG(5, (THIS_FILE, "pjsip_tpmgr_create()")); + /* Register mod_msg_print module. */ + status = pjsip_endpt_register_module(endpt, &mod_msg_print); + if (status != PJ_SUCCESS) + return status; + /* Create and initialize transport manager. */ mgr = pj_pool_zalloc(pool, sizeof(*mgr)); mgr->endpt = endpt; - mgr->msg_cb = cb; + mgr->on_rx_msg = rx_cb; + mgr->on_tx_msg = tx_cb; pj_list_init(&mgr->factory_list); mgr->table = pj_hash_create(pool, PJSIP_TPMGR_HTABLE_SIZE); @@ -587,6 +746,8 @@ PJ_DEF(pj_status_t) pjsip_tpmgr_create( pj_pool_t *pool, return status; #endif + PJ_LOG(5, (THIS_FILE, "Transport manager created.")); + *p_mgr = mgr; return PJ_SUCCESS; } @@ -600,12 +761,9 @@ PJ_DEF(pj_status_t) pjsip_tpmgr_destroy( pjsip_tpmgr *mgr ) { pj_hash_iterator_t itr_val; pj_hash_iterator_t *itr; + pjsip_endpoint *endpt = mgr->endpt; - PJ_LOG(5, (THIS_FILE, "pjsip_tpmgr_destroy()")); - -#if defined(PJ_DEBUG) && PJ_DEBUG!=0 - pj_assert(pj_atomic_get(mgr->tdata_counter) == 0); -#endif + PJ_LOG(5, (THIS_FILE, "Destroying transport manager")); pj_lock_acquire(mgr->lock); @@ -618,8 +776,7 @@ PJ_DEF(pj_status_t) pjsip_tpmgr_destroy( pjsip_tpmgr *mgr ) next = pj_hash_next(mgr->table, itr); - pj_atomic_set(transport->ref_cnt, 0); - pjsip_transport_unregister(mgr, transport); + destroy_transport(mgr, transport); itr = next; } @@ -627,6 +784,19 @@ PJ_DEF(pj_status_t) pjsip_tpmgr_destroy( pjsip_tpmgr *mgr ) pj_lock_release(mgr->lock); pj_lock_destroy(mgr->lock); + /* Unregister mod_msg_print. */ + if (mod_msg_print.id != -1) { + pjsip_endpt_unregister_module(endpt, &mod_msg_print); + } + +#if defined(PJ_DEBUG) && PJ_DEBUG!=0 + /* If you encounter assert error on this line, it means there are + * leakings in transmit data (i.e. some transmit data have not been + * destroyed). + */ + pj_assert(pj_atomic_get(mgr->tdata_counter) == 0); +#endif + return PJ_SUCCESS; } @@ -685,7 +855,7 @@ PJ_DEF(pj_ssize_t) pjsip_tpmgr_receive_packet( pjsip_tpmgr *mgr, &msg_fragment_size); if (msg_status != PJ_SUCCESS) { if (remaining_len == PJSIP_MAX_PKT_LEN) { - mgr->msg_cb(mgr->endpt, PJSIP_ERXOVERFLOW, rdata); + mgr->on_rx_msg(mgr->endpt, PJSIP_ERXOVERFLOW, rdata); /* Exhaust all data. */ return rdata->pkt_info.len; } else { @@ -702,7 +872,7 @@ PJ_DEF(pj_ssize_t) pjsip_tpmgr_receive_packet( pjsip_tpmgr *mgr, rdata->msg_info.msg = msg = pjsip_parse_rdata( current_pkt, msg_fragment_size, rdata); if (msg == NULL) { - mgr->msg_cb(mgr->endpt, PJSIP_EINVALIDMSG, rdata); + mgr->on_rx_msg(mgr->endpt, PJSIP_EINVALIDMSG, rdata); goto finish_process_fragment; } @@ -713,7 +883,7 @@ PJ_DEF(pj_ssize_t) pjsip_tpmgr_receive_packet( pjsip_tpmgr *mgr, rdata->msg_info.via == NULL || rdata->msg_info.cseq == NULL) { - mgr->msg_cb(mgr->endpt, PJSIP_EMISSINGHDR, rdata); + mgr->on_rx_msg(mgr->endpt, PJSIP_EMISSINGHDR, rdata); goto finish_process_fragment; } @@ -737,7 +907,7 @@ PJ_DEF(pj_ssize_t) pjsip_tpmgr_receive_packet( pjsip_tpmgr *mgr, if (hdr != &msg->hdr) { hdr = pjsip_msg_find_hdr(msg, PJSIP_H_VIA, hdr); if (hdr) { - mgr->msg_cb(mgr->endpt, PJSIP_EMULTIPLEVIA, rdata); + mgr->on_rx_msg(mgr->endpt, PJSIP_EMULTIPLEVIA, rdata); goto finish_process_fragment; } } @@ -745,7 +915,7 @@ PJ_DEF(pj_ssize_t) pjsip_tpmgr_receive_packet( pjsip_tpmgr *mgr, /* Call the transport manager's upstream message callback. */ - mgr->msg_cb(mgr->endpt, PJ_SUCCESS, rdata); + mgr->on_rx_msg(mgr->endpt, PJ_SUCCESS, rdata); finish_process_fragment: @@ -795,17 +965,25 @@ PJ_DEF(pj_status_t) pjsip_tpmgr_acquire_transport(pjsip_tpmgr *mgr, unsigned flag = pjsip_transport_get_flag_from_type(type); const pj_sockaddr *remote_addr = (const pj_sockaddr*)remote; - /* For datagram transports, try lookup with zero address. + /* Ignore address for loop transports. */ + if (type == PJSIP_TRANSPORT_LOOP || + type == PJSIP_TRANSPORT_LOOP_DGRAM) + { + pj_sockaddr_in *addr = (pj_sockaddr_in*)&key.addr; + + pj_memset(addr, 0, sizeof(pj_sockaddr_in)); + key_len = sizeof(key.type) + sizeof(pj_sockaddr_in); + transport = pj_hash_get(mgr->table, &key, key_len); + } + /* For datagram INET transports, try lookup with zero address. */ - if ( (flag & PJSIP_TRANSPORT_DATAGRAM) && - (remote_addr->sa_family == PJ_AF_INET)) + else if ((flag & PJSIP_TRANSPORT_DATAGRAM) && + (remote_addr->sa_family == PJ_AF_INET)) { pj_sockaddr_in *addr = (pj_sockaddr_in*)&key.addr; pj_memset(addr, 0, sizeof(pj_sockaddr_in)); addr->sin_family = PJ_AF_INET; - addr->sin_addr.s_addr = 0; - addr->sin_port = 0; key_len = sizeof(key.type) + sizeof(pj_sockaddr_in); transport = pj_hash_get(mgr->table, &key, key_len); diff --git a/pjsip/src/pjsip/sip_transport_loop.c b/pjsip/src/pjsip/sip_transport_loop.c index 38f44cea..de2f85ae 100644 --- a/pjsip/src/pjsip/sip_transport_loop.c +++ b/pjsip/src/pjsip/sip_transport_loop.c @@ -27,9 +27,6 @@ #include <pj/compat/socket.h> -#define FAIL_IMMEDIATE 1 -#define FAIL_CALLBACK 2 - #define ADDR_LOOP "128.0.0.1" #define ADDR_LOOP_DGRAM "129.0.0.1" @@ -61,7 +58,8 @@ struct loop_transport pj_bool_t thread_quit_flag; pj_bool_t discard; int fail_mode; - unsigned delay; + unsigned recv_delay; + unsigned send_delay; struct recv_list recv_list; struct send_list send_list; }; @@ -100,7 +98,7 @@ struct recv_list *create_incoming_packet( struct loop_transport *loop, /* When do we need to "deliver" this packet. */ pj_gettimeofday(&pkt->rdata.pkt_info.timestamp); - pkt->rdata.pkt_info.timestamp.msec += loop->delay; + pkt->rdata.pkt_info.timestamp.msec += loop->recv_delay; pj_time_val_normalize(&pkt->rdata.pkt_info.timestamp); /* Done. */ @@ -130,7 +128,7 @@ static pj_status_t add_notification( struct loop_transport *loop, sent_status->callback = callback; pj_gettimeofday(&sent_status->sent_time); - sent_status->sent_time.msec += loop->delay; + sent_status->sent_time.msec += loop->send_delay; pj_time_val_normalize(&sent_status->sent_time); pj_lock_acquire(loop->base.lock); @@ -160,17 +158,16 @@ static pj_status_t loop_send_msg( pjsip_transport *tp, PJ_UNUSED_ARG(addr_len); - /* Need to send failure immediately? */ - if (loop->fail_mode == FAIL_IMMEDIATE) { - return PJ_STATUS_FROM_OS(OSERR_ECONNRESET); - - /* Need to send failure later? */ - } else if (loop->fail_mode == FAIL_CALLBACK) { - - add_notification(loop, tdata, -PJ_STATUS_FROM_OS(OSERR_ECONNRESET), - token, cb); + /* Need to send failure? */ + if (loop->fail_mode) { + if (loop->send_delay == 0) { + return PJ_STATUS_FROM_OS(OSERR_ECONNRESET); + } else { + add_notification(loop, tdata, -PJ_STATUS_FROM_OS(OSERR_ECONNRESET), + token, cb); - return PJ_EPENDING; + return PJ_EPENDING; + } } /* Discard any packets? */ @@ -183,7 +180,7 @@ static pj_status_t loop_send_msg( pjsip_transport *tp, return PJ_ENOMEM; /* If delay is not configured, deliver this packet now! */ - if (loop->delay == 0) { + if (loop->recv_delay == 0) { pj_ssize_t size_eaten; size_eaten = pjsip_tpmgr_receive_packet( loop->base.tpmgr, @@ -192,20 +189,22 @@ static pj_status_t loop_send_msg( pjsip_transport *tp, pjsip_endpt_release_pool(loop->base.endpt, recv_pkt->rdata.tp_info.pool); - return PJ_SUCCESS; } else { /* Otherwise if delay is configured, add the "packet" to the - * receive list to be processed by worker thread, and add - * pending notification for calling the callback. + * receive list to be processed by worker thread. */ - add_notification(loop, tdata, tdata->buf.cur - tdata->buf.start, - token, cb); - pj_lock_acquire(loop->base.lock); pj_list_push_back(&loop->recv_list, recv_pkt); pj_lock_release(loop->base.lock); + } + + if (loop->send_delay != 0) { + add_notification(loop, tdata, tdata->buf.cur - tdata->buf.start, + token, cb); return PJ_EPENDING; + } else { + return PJ_SUCCESS; } } @@ -223,6 +222,26 @@ static pj_status_t loop_destroy(pjsip_transport *tp) pj_thread_join(loop->thread); pj_thread_destroy(loop->thread); + /* Clear pending send notifications. */ + while (!pj_list_empty(&loop->send_list)) { + struct send_list *node = loop->send_list.next; + /* Notify callback. */ + if (node->callback) { + (*node->callback)(&loop->base, node->token, -PJSIP_ESHUTDOWN); + } + pj_list_erase(node); + pjsip_tx_data_dec_ref(node->tdata); + } + + /* Clear "incoming" packets in the queue. */ + while (!pj_list_empty(&loop->recv_list)) { + struct recv_list *node = loop->recv_list.next; + pj_list_erase(node); + pjsip_endpt_release_pool(loop->base.endpt, + node->rdata.tp_info.pool); + } + + /* Self destruct.. heheh.. */ pj_lock_destroy(loop->base.lock); pj_atomic_destroy(loop->base.ref_cnt); pjsip_endpt_release_pool(loop->base.endpt, loop->base.pool); @@ -238,7 +257,7 @@ static int loop_thread(void *arg) while (!loop->thread_quit_flag) { pj_time_val now; - pj_thread_sleep(10); + pj_thread_sleep(1); pj_gettimeofday(&now); pj_lock_acquire(loop->base.lock); @@ -320,7 +339,7 @@ PJ_DEF(pj_status_t) pjsip_loop_start( pjsip_endpoint *endpt, if (status != PJ_SUCCESS) goto on_error; loop->base.key.type = PJSIP_TRANSPORT_LOOP_DGRAM; - loop->base.key.rem_addr.sa_family = PJ_AF_INET; + //loop->base.key.rem_addr.sa_family = PJ_AF_INET; loop->base.type_name = "LOOP-DGRAM"; loop->base.info = "LOOP-DGRAM"; loop->base.flag = PJSIP_TRANSPORT_DATAGRAM; @@ -356,7 +375,9 @@ PJ_DEF(pj_status_t) pjsip_loop_start( pjsip_endpoint *endpt, * Done. */ - *transport = &loop->base; + if (transport) + *transport = &loop->base; + return PJ_SUCCESS; on_error: @@ -405,9 +426,9 @@ PJ_DEF(pj_status_t) pjsip_loop_set_failure( pjsip_transport *tp, } -PJ_DEF(pj_status_t) pjsip_loop_set_delay( pjsip_transport *tp, - unsigned delay, - unsigned *prev_value) +PJ_DEF(pj_status_t) pjsip_loop_set_recv_delay( pjsip_transport *tp, + unsigned delay, + unsigned *prev_value) { struct loop_transport *loop = (struct loop_transport*)tp; @@ -415,8 +436,37 @@ PJ_DEF(pj_status_t) pjsip_loop_set_delay( pjsip_transport *tp, tp->key.type == PJSIP_TRANSPORT_LOOP_DGRAM), PJ_EINVAL); if (prev_value) - *prev_value = loop->delay; - loop->delay = delay; + *prev_value = loop->recv_delay; + loop->recv_delay = delay; + + return PJ_SUCCESS; +} + +PJ_DEF(pj_status_t) pjsip_loop_set_send_callback_delay( pjsip_transport *tp, + unsigned delay, + unsigned *prev_value) +{ + struct loop_transport *loop = (struct loop_transport*)tp; + + PJ_ASSERT_RETURN(tp && (tp->key.type == PJSIP_TRANSPORT_LOOP || + tp->key.type == PJSIP_TRANSPORT_LOOP_DGRAM), PJ_EINVAL); + + if (prev_value) + *prev_value = loop->send_delay; + loop->send_delay = delay; + + return PJ_SUCCESS; +} + +PJ_DEF(pj_status_t) pjsip_loop_set_delay( pjsip_transport *tp, unsigned delay ) +{ + struct loop_transport *loop = (struct loop_transport*)tp; + + PJ_ASSERT_RETURN(tp && (tp->key.type == PJSIP_TRANSPORT_LOOP || + tp->key.type == PJSIP_TRANSPORT_LOOP_DGRAM), PJ_EINVAL); + + loop->recv_delay = delay; + loop->send_delay = delay; return PJ_SUCCESS; } diff --git a/pjsip/src/pjsip/sip_transport_udp.c b/pjsip/src/pjsip/sip_transport_udp.c index f925d8cd..010c53d9 100644 --- a/pjsip/src/pjsip/sip_transport_udp.c +++ b/pjsip/src/pjsip/sip_transport_udp.c @@ -58,8 +58,10 @@ static void udp_on_read_complete( pj_ioqueue_key_t *key, pj_status_t status; /* Don't do anything if transport is closing. */ - if (tp->is_closing) + if (tp->is_closing) { + tp->is_closing++; return; + } /* * The idea of the loop is to process immediate data received by @@ -228,10 +230,17 @@ static pj_status_t udp_destroy( pjsip_transport *transport ) tp->is_closing = 1; /* Cancel all pending operations. */ + /* blp: NO NO NO... + * No need to post queued completion as we poll the ioqueue until + * we've got events anyway. Posting completion will only cause + * callback to be called twice with IOCP: one for the post completion + * and another one for closing the socket. + * for (i=0; i<tp->rdata_cnt; ++i) { pj_ioqueue_post_completion(tp->key, &tp->rdata[i]->tp_info.op_key.op_key, -1); } + */ /* Unregister from ioqueue. */ if (tp->key) @@ -241,6 +250,20 @@ static pj_status_t udp_destroy( pjsip_transport *transport ) if (tp->sock && tp->sock != PJ_INVALID_SOCKET) pj_sock_close(tp->sock); + /* Must poll ioqueue because IOCP calls the callback when socket + * is closed. We poll the ioqueue until all pending callbacks + * have been called. + */ + for (i=0; i<50 && tp->is_closing < 1+tp->rdata_cnt; ++i) { + int cnt; + pj_time_val timeout = {0, 1}; + + cnt = pj_ioqueue_poll(pjsip_endpt_get_ioqueue(transport->endpt), + &timeout); + if (cnt == 0) + break; + } + /* Destroy reference counter. */ if (tp->base.ref_cnt) pj_atomic_destroy(tp->base.ref_cnt); diff --git a/pjsip/src/pjsip/sip_util.c b/pjsip/src/pjsip/sip_util.c index 0760e322..d6ba5e97 100644 --- a/pjsip/src/pjsip/sip_util.c +++ b/pjsip/src/pjsip/sip_util.c @@ -129,11 +129,8 @@ static void init_request_throw( pjsip_endpoint *endpt, msg->body = body; } - PJ_LOG(4,(THIS_FILE, "Request %s (CSeq=%d/%.*s) created.", - tdata->obj_name, - param_cseq->cseq, - param_cseq->method.name.slen, - param_cseq->method.name.ptr)); + PJ_LOG(5,(THIS_FILE, "%s created.", + pjsip_tx_data_get_info(tdata))); } @@ -162,8 +159,6 @@ PJ_DEF(pj_status_t) pjsip_endpt_create_request( pjsip_endpoint *endpt, pj_status_t status; PJ_USE_EXCEPTION; - PJ_LOG(5,(THIS_FILE, "Entering pjsip_endpt_create_request()")); - status = pjsip_endpt_create_tdata(endpt, &tdata); if (status != PJ_SUCCESS) return status; @@ -272,8 +267,6 @@ pjsip_endpt_create_request_from_hdr( pjsip_endpoint *endpt, pj_status_t status; PJ_USE_EXCEPTION; - PJ_LOG(5,(THIS_FILE, "Entering pjsip_endpt_create_request_from_hdr()")); - /* Check arguments. */ PJ_ASSERT_RETURN(endpt && method && param_target && param_from && param_to && p_tdata, PJ_EINVAL); @@ -343,10 +336,6 @@ PJ_DEF(pj_status_t) pjsip_endpt_create_response( pjsip_endpoint *endpt, req_msg = rdata->msg_info.msg; pj_assert(req_msg->type == PJSIP_REQUEST_MSG); - /* Log this action. */ - PJ_LOG(5,(THIS_FILE, "pjsip_endpt_create_response(rdata=%p, code=%d)", - rdata, st_code)); - /* Create a new transmit buffer. */ status = pjsip_endpt_create_tdata( endpt, &tdata); if (status != PJ_SUCCESS) @@ -408,6 +397,8 @@ PJ_DEF(pj_status_t) pjsip_endpt_create_response( pjsip_endpoint *endpt, /* All done. */ *p_tdata = tdata; + + PJ_LOG(5,(THIS_FILE, "%s created", pjsip_tx_data_get_info(tdata))); return PJ_SUCCESS; } @@ -432,9 +423,6 @@ PJ_DEF(pj_status_t) pjsip_endpt_create_ack( pjsip_endpoint *endpt, pjsip_to_hdr *to; pj_status_t status; - /* Log this action. */ - PJ_LOG(5,(THIS_FILE, "pjsip_endpt_create_ack(rdata=%p)", rdata)); - /* rdata must be a final response. */ pj_assert(rdata->msg_info.msg->type==PJSIP_RESPONSE_MSG && rdata->msg_info.msg->line.status.code >= 300); @@ -525,9 +513,6 @@ PJ_DEF(pj_status_t) pjsip_endpt_create_cancel( pjsip_endpoint *endpt, const pjsip_hdr *hdr; pj_status_t status; - /* Log this action. */ - PJ_LOG(5,(THIS_FILE, "pjsip_endpt_create_cancel(tdata=%p)", req_tdata)); - /* The transmit buffer must INVITE request. */ PJ_ASSERT_RETURN(req_tdata->msg->type == PJSIP_REQUEST_MSG && req_tdata->msg->line.req.method.id == PJSIP_INVITE_METHOD, @@ -702,13 +687,8 @@ PJ_DEF(pj_status_t) pjsip_get_request_addr( pjsip_tx_data *tdata, dest_info->addr.port = url->port; dest_info->type = pjsip_transport_get_type_from_name(&url->transport_param); -#if PJ_HAS_TCP - if (dest_info->type == PJSIP_TRANSPORT_TCP || - dest_info->type == PJSIP_TRANSPORT_SCTP) - { - dest_info->flag |= PJSIP_TRANSPORT_RELIABLE; - } -#endif + dest_info->flag = + pjsip_transport_get_flag_from_type(dest_info->type); } else { pj_assert(!"Unsupported URI scheme!"); PJ_TODO(SUPPORT_REQUEST_ADDR_RESOLUTION_FOR_TEL_URI); diff --git a/pjsip/src/test-pjsip/msg_logger.c b/pjsip/src/test-pjsip/msg_logger.c new file mode 100644 index 00000000..faa36b53 --- /dev/null +++ b/pjsip/src/test-pjsip/msg_logger.c @@ -0,0 +1,102 @@ +/* $Id$ */ +/* + * Copyright (C) 2003-2006 Benny Prijono <benny@prijono.org> + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + */ +#include "test.h" +#include <pjsip_core.h> +#include <pjlib.h> + +#define THIS_FILE "msg_logger.c" + +static pj_bool_t msg_log_enabled; + +static pj_bool_t on_rx_msg(pjsip_rx_data *rdata) +{ + if (msg_log_enabled) { + PJ_LOG(4,(THIS_FILE, "RX %d bytes %s from %s:%d:\n" + "%s\n" + "--end msg--", + rdata->msg_info.len, + pjsip_rx_data_get_info(rdata), + rdata->pkt_info.src_name, + rdata->pkt_info.src_port, + rdata->msg_info.msg_buf)); + } + + return PJ_FALSE; +} + +static pj_status_t on_tx_msg(pjsip_tx_data *tdata) +{ + if (msg_log_enabled) { + PJ_LOG(4,(THIS_FILE, "TX %d bytes %s to %s:%d:\n" + "%s\n" + "--end msg--", + (tdata->buf.cur - tdata->buf.start), + pjsip_tx_data_get_info(tdata), + tdata->tp_info.dst_name, + tdata->tp_info.dst_port, + tdata->buf.start)); + } + return PJ_SUCCESS; +} + + +/* Message logger module. */ +static pjsip_module mod_msg_logger = +{ + NULL, NULL, /* prev and next */ + { "mod-msg-logger", 14}, /* Name. */ + -1, /* Id */ + PJSIP_MOD_PRIORITY_TRANSPORT_LAYER-1,/* Priority */ + NULL, /* User data. */ + 0, /* Number of methods supported (=0). */ + { 0 }, /* Array of methods (none) */ + NULL, /* load() */ + NULL, /* start() */ + NULL, /* stop() */ + NULL, /* unload() */ + &on_rx_msg, /* on_rx_request() */ + &on_rx_msg, /* on_rx_response() */ + &on_tx_msg, /* on_tx_request() */ + &on_tx_msg, /* on_tx_response() */ + NULL, /* on_tsx_state() */ +}; + +int init_msg_logger(void) +{ + pj_status_t status; + + if (mod_msg_logger.id != -1) + return 0; + + status = pjsip_endpt_register_module(endpt, &mod_msg_logger); + if (status != PJ_SUCCESS) { + app_perror(" error registering module", status); + return -10; + } + + return 0; +} + +int msg_logger_set_enabled(pj_bool_t enabled) +{ + int val = msg_log_enabled; + msg_log_enabled = enabled; + return val; +} + diff --git a/pjsip/src/test-pjsip/msg_test.c b/pjsip/src/test-pjsip/msg_test.c index 11a69b43..f49f1256 100644 --- a/pjsip/src/test-pjsip/msg_test.c +++ b/pjsip/src/test-pjsip/msg_test.c @@ -23,6 +23,7 @@ #define POOL_SIZE 8000 #define LOOP 10000 #define AVERAGE_MSG_LEN 800 +#define THIS_FILE "msg_test.c" static pjsip_msg *create_msg0(pj_pool_t *pool); static pjsip_msg *create_msg1(pj_pool_t *pool); @@ -142,7 +143,7 @@ static pj_status_t test_entry( pj_pool_t *pool, struct test_msg *entry ) } } if (msg_size != entry->len) { - PJ_LOG(3,("", " error: size mismatch")); + PJ_LOG(3,(THIS_FILE, " error: size mismatch")); return -6; } pj_get_timestamp(&t2); @@ -162,7 +163,7 @@ parse_msg: if (entry->expected_status != STATUS_SYNTAX_ERROR) { status = -10; if (err_list.next != &err_list) { - PJ_LOG(3,("", " Syntax error in line %d col %d", + PJ_LOG(3,(THIS_FILE, " Syntax error in line %d col %d", err_list.next->line, err_list.next->col)); } goto on_return; @@ -207,14 +208,14 @@ parse_msg: } } else { if (parsed_msg->line.status.code != ref_msg->line.status.code) { - PJ_LOG(3,("", " error: status code mismatch")); + PJ_LOG(3,(THIS_FILE, " error: status code mismatch")); status = -32; goto on_return; } if (pj_strcmp(&parsed_msg->line.status.reason, &ref_msg->line.status.reason) != 0) { - PJ_LOG(3,("", " error: status text mismatch")); + PJ_LOG(3,(THIS_FILE, " error: status text mismatch")); status = -33; goto on_return; } @@ -243,7 +244,7 @@ parse_msg: if (pj_strcmp(&str1, &str2) != 0) { status = -60; - PJ_LOG(3,("", " error: header string mismatch:\n" + PJ_LOG(3,(THIS_FILE, " error: header string mismatch:\n" " h1='%s'\n" " h2='%s'\n", str1.ptr, str2.ptr)); @@ -683,7 +684,7 @@ int msg_test(void) pj_time_val elapsed; pj_highprec_t avg_detect, avg_parse, avg_print, kbytes; - PJ_LOG(3,("", " simple test..")); + PJ_LOG(3,(THIS_FILE, " simple test..")); for (i=0; i<PJ_ARRAY_SIZE(test_array); ++i) { pool = pjsip_endpt_create_pool(endpt, NULL, POOL_SIZE, POOL_SIZE); status = test_entry( pool, &test_array[i] ); @@ -693,7 +694,7 @@ int msg_test(void) return status; } - PJ_LOG(3,("", " benchmarking..")); + PJ_LOG(3,(THIS_FILE, " benchmarking..")); detect_len = parse_len = print_len = 0; zero.u64 = detect_time.u64 = parse_time.u64 = print_time.u64 = 0; @@ -717,10 +718,11 @@ int msg_test(void) pj_highprec_div(avg_detect, detect_len); avg_detect = 1000000 / avg_detect; - PJ_LOG(3,("", " %u.%u MB detected in %d.%03ds (avg=%d msg detection/sec)", - (unsigned)(detect_len/1000000), (unsigned)kbytes, - elapsed.sec, elapsed.msec, - (unsigned)avg_detect)); + PJ_LOG(3,(THIS_FILE, + " %u.%u MB detected in %d.%03ds (avg=%d msg detection/sec)", + (unsigned)(detect_len/1000000), (unsigned)kbytes, + elapsed.sec, elapsed.msec, + (unsigned)avg_detect)); kbytes = parse_len; pj_highprec_mod(kbytes, 1000000); @@ -731,10 +733,11 @@ int msg_test(void) pj_highprec_div(avg_parse, parse_len); avg_parse = 1000000 / avg_parse; - PJ_LOG(3,("", " %u.%u MB parsed in %d.%03ds (avg=%d msg parsing/sec)", - (unsigned)(parse_len/1000000), (unsigned)kbytes, - elapsed.sec, elapsed.msec, - (unsigned)avg_parse)); + PJ_LOG(3,(THIS_FILE, + " %u.%u MB parsed in %d.%03ds (avg=%d msg parsing/sec)", + (unsigned)(parse_len/1000000), (unsigned)kbytes, + elapsed.sec, elapsed.msec, + (unsigned)avg_parse)); kbytes = print_len; pj_highprec_mod(kbytes, 1000000); @@ -745,10 +748,11 @@ int msg_test(void) pj_highprec_div(avg_print, print_len); avg_print = 1000000 / avg_print; - PJ_LOG(3,("", " %u.%u MB printed in %d.%03ds (avg=%d msg print/sec)", - (unsigned)(print_len/1000000), (unsigned)kbytes, - elapsed.sec, elapsed.msec, - (unsigned)avg_print)); + PJ_LOG(3,(THIS_FILE, + " %u.%u MB printed in %d.%03ds (avg=%d msg print/sec)", + (unsigned)(print_len/1000000), (unsigned)kbytes, + elapsed.sec, elapsed.msec, + (unsigned)avg_print)); return status; } diff --git a/pjsip/src/test-pjsip/test.c b/pjsip/src/test-pjsip/test.c index fbb72917..fdc6a7d8 100644 --- a/pjsip/src/test-pjsip/test.c +++ b/pjsip/src/test-pjsip/test.c @@ -22,10 +22,12 @@ #include <pjlib.h> #include <pjsip_core.h> +#define THIS_FILE "test.c" + #define DO_TEST(test) do { \ - PJ_LOG(3, ("test", "Running %s...", #test)); \ + PJ_LOG(3, (THIS_FILE, "Running %s...", #test)); \ rc = test; \ - PJ_LOG(3, ("test", \ + PJ_LOG(3, (THIS_FILE, \ "%s(%d)", \ (rc ? "..ERROR" : "..success"), rc)); \ if (rc!=0) goto on_return; \ @@ -42,8 +44,28 @@ void app_perror(const char *msg, pj_status_t rc) PJ_CHECK_STACK(); pjsip_strerror(rc, errbuf, sizeof(errbuf)); - PJ_LOG(3,("test", "%s: [pj_status_t=%d] %s", msg, rc, errbuf)); + PJ_LOG(3,(THIS_FILE, "%s: [pj_status_t=%d] %s", msg, rc, errbuf)); + +} + +void flush_events(unsigned duration) +{ + pj_time_val stop_time; + + pj_gettimeofday(&stop_time); + stop_time.msec += duration; + pj_time_val_normalize(&stop_time); + + /* Process all events for the specified duration. */ + for (;;) { + pj_time_val timeout = {0, 1}, now; + + pjsip_endpt_handle_events(endpt, &timeout); + pj_gettimeofday(&now); + if (PJ_TIME_VAL_GTE(now, stop_time)) + break; + } } pj_status_t register_static_modules(pj_size_t *count, pjsip_module **modules) @@ -59,9 +81,11 @@ int test_main(void) const char *filename; int line; - pj_log_set_level(3); + pj_log_set_level(5); + /* pj_log_set_decor(PJ_LOG_HAS_NEWLINE | PJ_LOG_HAS_TIME | PJ_LOG_HAS_MICRO_SEC); + */ if ((rc=pj_init()) != PJ_SUCCESS) { app_perror("pj_init", rc); @@ -79,30 +103,50 @@ int test_main(void) return rc; } - PJ_LOG(3,("","")); + PJ_LOG(3,(THIS_FILE,"")); + + /* Init logger module. */ + init_msg_logger(); + msg_logger_set_enabled(1); + + /* Start transaction layer module. */ + rc = pjsip_tsx_layer_init(endpt); + if (rc != PJ_SUCCESS) { + app_perror(" Error initializing transaction module", rc); + goto on_return; + } + + /* Create loop transport. */ + rc = pjsip_loop_start(endpt, NULL); + if (rc != PJ_SUCCESS) { + app_perror(" error: unable to create datagram loop transport", + rc); + goto on_return; + } //DO_TEST(uri_test()); //DO_TEST(msg_test()); //DO_TEST(txdata_test()); //DO_TEST(transport_udp_test()); - DO_TEST(transport_loop_test()); - //DO_TEST(tsx_uac_test()); + //DO_TEST(transport_loop_test()); + //DO_TEST(tsx_basic_test()); + DO_TEST(tsx_uac_test()); on_return: pjsip_endpt_destroy(endpt); pj_caching_pool_destroy(&caching_pool); - PJ_LOG(3,("test", "")); + PJ_LOG(3,(THIS_FILE, "")); pj_thread_get_stack_info(pj_thread_this(), &filename, &line); - PJ_LOG(3,("test", "Stack max usage: %u, deepest: %s:%u", + PJ_LOG(3,(THIS_FILE, "Stack max usage: %u, deepest: %s:%u", pj_thread_get_stack_max_usage(pj_thread_this()), filename, line)); if (rc == 0) - PJ_LOG(3,("test", "Looks like everything is okay!..")); + PJ_LOG(3,(THIS_FILE, "Looks like everything is okay!..")); else - PJ_LOG(3,("test", "Test completed with error(s)")); + PJ_LOG(3,(THIS_FILE, "Test completed with error(s)")); return 0; } diff --git a/pjsip/src/test-pjsip/test.h b/pjsip/src/test-pjsip/test.h index db12e390..2012781c 100644 --- a/pjsip/src/test-pjsip/test.h +++ b/pjsip/src/test-pjsip/test.h @@ -32,6 +32,7 @@ int msg_test(void); int txdata_test(void); int transport_udp_test(void); int transport_loop_test(void); +int tsx_basic_test(void); int tsx_uac_test(void); /* Transport test helpers (transport_test.c). */ @@ -41,13 +42,16 @@ int transport_send_recv_test( pjsip_transport_type_e tp_type, char *target_url ); int transport_rt_test( pjsip_transport_type_e tp_type, pjsip_transport *ref_tp, - char *target_url ); + char *target_url, + int *pkt_lost); /* Test main entry */ int test_main(void); /* Test utilities. */ void app_perror(const char *msg, pj_status_t status); - +int init_msg_logger(void); +int msg_logger_set_enabled(pj_bool_t enabled); +void flush_events(unsigned duration); #endif /* __TEST_H__ */ diff --git a/pjsip/src/test-pjsip/transport_loop_test.c b/pjsip/src/test-pjsip/transport_loop_test.c index 467f327f..f4e6bb3c 100644 --- a/pjsip/src/test-pjsip/transport_loop_test.c +++ b/pjsip/src/test-pjsip/transport_loop_test.c @@ -21,40 +21,25 @@ #include <pjsip_core.h> #include <pjlib.h> +#define THIS_FILE "transport_loop_test.c" + static int datagram_loop_test() { - pjsip_transport *loop, *tp; - pj_str_t s; - int i, log_level; + pjsip_transport *loop; + int i, pkt_lost; pj_sockaddr_in addr; pj_status_t status; - PJ_LOG(3,("", "testing datagram loop transport")); - - /* Create loop transport. */ - status = pjsip_loop_start(endpt, &loop); - if (status != PJ_SUCCESS) { - app_perror(" error: unable to create datagram loop transport", - status); - return -10; - } - - /* Create dummy address. */ - pj_sockaddr_in_init(&addr, pj_cstr(&s, "130.0.0.1"), TEST_UDP_PORT); + PJ_LOG(3,(THIS_FILE, "testing datagram loop transport")); /* Test acquire transport. */ status = pjsip_endpt_acquire_transport( endpt, PJSIP_TRANSPORT_LOOP_DGRAM, - &addr, sizeof(addr), &tp); + &addr, sizeof(addr), &loop); if (status != PJ_SUCCESS) { - app_perror(" error: unable to acquire transport", status); + app_perror(" error: loop transport is not configured", status); return -20; } - /* Check that this is the right transport. */ - if (tp != loop) { - return -30; - } - /* Test basic transport attributes */ status = generic_transport_test(loop); if (status != PJ_SUCCESS) @@ -68,45 +53,40 @@ static int datagram_loop_test() return status; } - /* For multithreaded round-trip test to work, delay must be set - * (otherwise functions will be called recursively until no memory is - * left in the system) - */ - - /* Put delay. */ - pjsip_loop_set_delay(loop, 1, NULL); - /* Multi-threaded round-trip test. */ - status = transport_rt_test(PJSIP_TRANSPORT_LOOP_DGRAM, tp, - "sip:bob@130.0.0.1;transport=loop-dgram"); + status = transport_rt_test(PJSIP_TRANSPORT_LOOP_DGRAM, loop, + "sip:bob@130.0.0.1;transport=loop-dgram", + &pkt_lost); if (status != 0) return status; + if (pkt_lost != 0) { + PJ_LOG(3,(THIS_FILE, " error: %d packet(s) was lost", pkt_lost)); + return -40; + } - /* Next test will test without delay. - * This will stress-test the system. - */ - PJ_LOG(3,(""," performing another multithreaded round-trip test...")); - - /* Remove delay. */ - pjsip_loop_set_delay(loop, 0, NULL); - - /* Ignore errors. */ - log_level = pj_log_get_level(); - pj_log_set_level(2); + /* Put delay. */ + PJ_LOG(3,(THIS_FILE," setting network delay to 10 ms")); + pjsip_loop_set_delay(loop, 10); /* Multi-threaded round-trip test. */ - status = transport_rt_test(PJSIP_TRANSPORT_LOOP_DGRAM, tp, - "sip:bob@130.0.0.1;transport=loop-dgram"); + status = transport_rt_test(PJSIP_TRANSPORT_LOOP_DGRAM, loop, + "sip:bob@130.0.0.1;transport=loop-dgram", + &pkt_lost); if (status != 0) return status; - /* Restore log level. */ - pj_log_set_level(log_level); + if (pkt_lost != 0) { + PJ_LOG(3,(THIS_FILE, " error: %d packet(s) was lost", pkt_lost)); + return -50; + } + + /* Restore delay. */ + pjsip_loop_set_delay(loop, 0); /* Check that reference counter is one. */ if (pj_atomic_get(loop->ref_cnt) != 1) { - return -30; + return -50; } /* Decrement reference. */ diff --git a/pjsip/src/test-pjsip/transport_test.c b/pjsip/src/test-pjsip/transport_test.c index 76b6bb9e..b57fedbf 100644 --- a/pjsip/src/test-pjsip/transport_test.c +++ b/pjsip/src/test-pjsip/transport_test.c @@ -21,6 +21,8 @@ #include <pjsip_core.h> #include <pjlib.h> +#define THIS_FILE "transport_test.c" + /////////////////////////////////////////////////////////////////////////////// /* * Generic testing for transport, to make sure that basic @@ -28,7 +30,7 @@ */ int generic_transport_test(pjsip_transport *tp) { - PJ_LOG(3,("", " structure test...")); + PJ_LOG(3,(THIS_FILE, " structure test...")); /* Check that local address name is valid. */ { @@ -37,7 +39,7 @@ int generic_transport_test(pjsip_transport *tp) /* Note: inet_aton() returns non-zero if addr is valid! */ if (pj_inet_aton(&tp->local_name.host, &addr) != 0) { if (addr.s_addr==PJ_INADDR_ANY || addr.s_addr==PJ_INADDR_NONE) { - PJ_LOG(3,("", " Error: invalid address name")); + PJ_LOG(3,(THIS_FILE, " Error: invalid address name")); return -420; } } else { @@ -121,13 +123,6 @@ static pj_bool_t my_on_rx_request(pjsip_rx_data *rdata) pjsip_response_addr res_addr; pj_status_t status; - PJ_LOG(4,("test", "Received %d bytes request: --begin-\n" - "%s\n" - "--end--", - rdata->msg_info.len, - rdata->msg_info.msg_buf)); - - status = pjsip_endpt_create_response( endpt, rdata, 200, NULL, &tdata); if (status != PJ_SUCCESS) { recv_status = status; @@ -155,12 +150,6 @@ static pj_bool_t my_on_rx_request(pjsip_rx_data *rdata) static pj_bool_t my_on_rx_response(pjsip_rx_data *rdata) { if (pj_strcmp2(&rdata->msg_info.call_id, CALL_ID_HDR) == 0) { - PJ_LOG(4,("test", "Received %d bytes response: --begin-\n" - "%s\n" - "--end--", - rdata->msg_info.len, - rdata->msg_info.msg_buf)); - pj_get_timestamp(&my_recv_time); recv_status = PJ_SUCCESS; return PJ_TRUE; @@ -189,13 +178,14 @@ int transport_send_recv_test( pjsip_transport_type_e tp_type, pjsip_transport *ref_tp, char *target_url ) { + pj_bool_t msg_log_enabled; pj_status_t status; pj_str_t target, from, to, contact, call_id, body; pjsip_method method; pjsip_tx_data *tdata; pj_time_val timeout; - PJ_LOG(3,("", " single message round-trip test...")); + PJ_LOG(3,(THIS_FILE, " single message round-trip test...")); /* Register out test module to receive the message (if necessary). */ if (my_module.id == -1) { @@ -206,6 +196,9 @@ int transport_send_recv_test( pjsip_transport_type_e tp_type, } } + /* Disable message logging. */ + msg_log_enabled = msg_logger_set_enabled(0); + /* Create a request message. */ target = pj_str(target_url); from = pj_str(FROM_HDR); @@ -249,7 +242,7 @@ int transport_send_recv_test( pjsip_transport_type_e tp_type, pj_gettimeofday(&now); if (PJ_TIME_VAL_GTE(now, timeout)) { - PJ_LOG(3,("", " error: timeout in send/recv test")); + PJ_LOG(3,(THIS_FILE, " error: timeout in send/recv test")); status = -540; goto on_return; } @@ -278,9 +271,12 @@ int transport_send_recv_test( pjsip_transport_type_e tp_type, if (status == PJ_SUCCESS) { unsigned usec_rt; usec_rt = pj_elapsed_usec(&my_send_time, &my_recv_time); - PJ_LOG(3,("", " round-trip = %d usec", usec_rt)); + PJ_LOG(3,(THIS_FILE, " round-trip = %d usec", usec_rt)); } + /* Restore message logging. */ + msg_logger_set_enabled(msg_log_enabled); + status = PJ_SUCCESS; on_return: @@ -327,6 +323,9 @@ static struct pj_timestamp total_rt_time; int sent_request_count, recv_response_count; pj_str_t call_id; + pj_timer_entry timeout_timer; + pj_timer_entry tx_timer; + pj_mutex_t *mutex; } rt_test_data[16]; static char rt_target_uri[64]; @@ -371,6 +370,9 @@ static pj_status_t rt_send_request(int thread_id) pj_status_t status; pj_str_t target, from, to, contact, call_id; pjsip_tx_data *tdata; + pj_time_val timeout_delay; + + pj_mutex_lock(rt_test_data[thread_id].mutex); /* Create a request message. */ target = pj_str(rt_target_uri); @@ -384,7 +386,8 @@ static pj_status_t rt_send_request(int thread_id) &contact, &call_id, -1, NULL, &tdata ); if (status != PJ_SUCCESS) { - app_perror(" error: unable to create request", status); + app_perror(" error: unable to create request", status); + pj_mutex_unlock(rt_test_data[thread_id].mutex); return -610; } @@ -395,14 +398,25 @@ static pj_status_t rt_send_request(int thread_id) status = pjsip_endpt_send_request_stateless( endpt, tdata, NULL, NULL); if (status != PJ_SUCCESS) { /* Immediate error! */ - app_perror(" error: send request", status); + app_perror(" error: send request", status); pjsip_tx_data_dec_ref(tdata); + pj_mutex_unlock(rt_test_data[thread_id].mutex); return -620; } /* Update counter. */ rt_test_data[thread_id].sent_request_count++; + /* Set timeout timer. */ + if (rt_test_data[thread_id].timeout_timer.user_data != NULL) { + pjsip_endpt_cancel_timer(endpt, &rt_test_data[thread_id].timeout_timer); + } + timeout_delay.sec = 100; timeout_delay.msec = 0; + rt_test_data[thread_id].timeout_timer.user_data = (void*)1; + pjsip_endpt_schedule_timer(endpt, &rt_test_data[thread_id].timeout_timer, + &timeout_delay); + + pj_mutex_unlock(rt_test_data[thread_id].mutex); return PJ_SUCCESS; } @@ -413,6 +427,11 @@ static pj_bool_t rt_on_rx_response(pjsip_rx_data *rdata) int thread_id = (*pos - '0'); pj_timestamp recv_time; + pj_mutex_lock(rt_test_data[thread_id].mutex); + + /* Stop timer. */ + pjsip_endpt_cancel_timer(endpt, &rt_test_data[thread_id].timeout_timer); + /* Update counter and end-time. */ rt_test_data[thread_id].recv_response_count++; pj_get_timestamp(&recv_time); @@ -420,14 +439,55 @@ static pj_bool_t rt_on_rx_response(pjsip_rx_data *rdata) pj_sub_timestamp(&recv_time, &rt_test_data[thread_id].send_time); pj_add_timestamp(&rt_test_data[thread_id].total_rt_time, &recv_time); - if (!rt_stop) - rt_send_request(thread_id); + if (!rt_stop) { + pj_time_val tx_delay = { 0, 0 }; + pj_assert(rt_test_data[thread_id].tx_timer.user_data == NULL); + rt_test_data[thread_id].tx_timer.user_data = (void*)1; + pjsip_endpt_schedule_timer(endpt, &rt_test_data[thread_id].tx_timer, + &tx_delay); + } + + pj_mutex_unlock(rt_test_data[thread_id].mutex); + return PJ_TRUE; } return PJ_FALSE; } -static int rt_thread(void *arg) +static void rt_timeout_timer( pj_timer_heap_t *timer_heap, + struct pj_timer_entry *entry ) +{ + pj_mutex_lock(rt_test_data[entry->id].mutex); + + PJ_UNUSED_ARG(timer_heap); + PJ_LOG(3,(THIS_FILE, " timeout waiting for response")); + rt_test_data[entry->id].timeout_timer.user_data = NULL; + + if (rt_test_data[entry->id].tx_timer.user_data == NULL) { + pj_time_val delay = { 0, 0 }; + rt_test_data[entry->id].tx_timer.user_data = (void*)1; + pjsip_endpt_schedule_timer(endpt, &rt_test_data[entry->id].tx_timer, + &delay); + } + + pj_mutex_unlock(rt_test_data[entry->id].mutex); +} + +static void rt_tx_timer( pj_timer_heap_t *timer_heap, + struct pj_timer_entry *entry ) +{ + pj_mutex_lock(rt_test_data[entry->id].mutex); + + PJ_UNUSED_ARG(timer_heap); + pj_assert(rt_test_data[entry->id].tx_timer.user_data != NULL); + rt_test_data[entry->id].tx_timer.user_data = NULL; + rt_send_request(entry->id); + + pj_mutex_unlock(rt_test_data[entry->id].mutex); +} + + +static int rt_worker_thread(void *arg) { int i, thread_id = (int)arg; pj_time_val poll_delay = { 0, 10 }; @@ -435,10 +495,6 @@ static int rt_thread(void *arg) /* Sleep to allow main threads to run. */ pj_thread_sleep(10); - /* Send the first request. */ - if (rt_send_request(thread_id) != PJ_SUCCESS) - return -1; - while (!rt_stop) { pjsip_endpt_handle_events(endpt, &poll_delay); } @@ -452,13 +508,14 @@ static int rt_thread(void *arg) int transport_rt_test( pjsip_transport_type_e tp_type, pjsip_transport *ref_tp, - char *target_url ) + char *target_url, + int *lost) { enum { THREADS = 4, INTERVAL = 10 }; int i; pj_status_t status; pj_pool_t *pool; - pj_bool_t is_reliable; + pj_bool_t logger_enabled; pj_timestamp zero_time, total_time; unsigned usec_rt; @@ -466,11 +523,13 @@ int transport_rt_test( pjsip_transport_type_e tp_type, unsigned total_recv; - PJ_LOG(3,("", " multithreaded round-trip test (%d threads)...", + PJ_LOG(3,(THIS_FILE, " multithreaded round-trip test (%d threads)...", THREADS)); - PJ_LOG(3,("", " this will take approx %d seconds, please wait..", INTERVAL)); + PJ_LOG(3,(THIS_FILE, " this will take approx %d seconds, please wait..", + INTERVAL)); - is_reliable = (pjsip_transport_get_flag_from_type(tp_type) & PJSIP_TRANSPORT_RELIABLE); + /* Make sure msg logger is disabled. */ + logger_enabled = msg_logger_set_enabled(0); /* Register module (if not yet registered) */ if (rt_module.id == -1) { @@ -498,14 +557,27 @@ int transport_rt_test( pjsip_transport_type_e tp_type, pj_memset(&rt_test_data[i], 0, sizeof(rt_test_data[i])); + /* Init timer entry */ + rt_test_data[i].tx_timer.id = i; + rt_test_data[i].tx_timer.cb = &rt_tx_timer; + rt_test_data[i].timeout_timer.id = i; + rt_test_data[i].timeout_timer.cb = &rt_timeout_timer; + /* Generate Call-ID for each thread. */ rt_test_data[i].call_id.ptr = pj_pool_alloc(pool, rt_call_id.slen+1); pj_strcpy(&rt_test_data[i].call_id, &rt_call_id); buf[0] = '0' + i; pj_strcat(&rt_test_data[i].call_id, &str_id); + /* Init mutex. */ + status = pj_mutex_create_recursive(pool, "rt", &rt_test_data[i].mutex); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to create mutex", status); + return -615; + } + /* Create thread, suspended. */ - status = pj_thread_create(pool, "rttest%p", &rt_thread, (void*)i, 0, + status = pj_thread_create(pool, "rttest%p", &rt_worker_thread, (void*)i, 0, PJ_THREAD_SUSPENDED, &rt_test_data[i].thread); if (status != PJ_SUCCESS) { app_perror(" error: unable to create thread", status); @@ -515,7 +587,12 @@ int transport_rt_test( pjsip_transport_type_e tp_type, /* Start threads! */ for (i=0; i<THREADS; ++i) { + pj_time_val delay = {0,0}; pj_thread_resume(rt_test_data[i].thread); + + /* Schedule first message transmissions. */ + rt_test_data[i].tx_timer.user_data = (void*)1; + pjsip_endpt_schedule_timer(endpt, &rt_test_data[i].tx_timer, &delay); } /* Sleep for some time. */ @@ -530,6 +607,12 @@ int transport_rt_test( pjsip_transport_type_e tp_type, pj_thread_destroy(rt_test_data[i].thread); } + /* Destroy rt_test_data */ + for (i=0; i<THREADS; ++i) { + pj_mutex_destroy(rt_test_data[i].mutex); + pjsip_endpt_cancel_timer(endpt, &rt_test_data[i].timeout_timer); + } + /* Gather statistics. */ pj_memset(&total_time, 0, sizeof(total_time)); pj_memset(&zero_time, 0, sizeof(zero_time)); @@ -546,19 +629,19 @@ int transport_rt_test( pjsip_transport_type_e tp_type, else total_time.u64 = 0; usec_rt = pj_elapsed_usec(&zero_time, &total_time); - PJ_LOG(3,("", " done.")); - PJ_LOG(3,("", " total %d messages sent", total_sent)); - if (total_sent-total_recv) - PJ_LOG(2,("", " total %d messages LOST", total_sent-total_recv)); - else - PJ_LOG(3,("", " no message was lost")); - PJ_LOG(3,("", " average round-trip=%d usec", usec_rt)); + PJ_LOG(3,(THIS_FILE, " done.")); + PJ_LOG(3,(THIS_FILE, " total %d messages sent", total_sent)); + PJ_LOG(3,(THIS_FILE, " average round-trip=%d usec", usec_rt)); pjsip_endpt_release_pool(endpt, pool); - if (is_reliable && (total_sent != total_recv)) { - PJ_LOG(3,("", " error: %d messages lost", total_sent-total_recv)); - return -650; - } + *lost = total_sent-total_recv; + + /* Flush events. */ + flush_events(500); + + /* Restore msg logger. */ + msg_logger_set_enabled(logger_enabled); + return 0; } diff --git a/pjsip/src/test-pjsip/transport_udp_test.c b/pjsip/src/test-pjsip/transport_udp_test.c index 0fdbddae..ebc0557d 100644 --- a/pjsip/src/test-pjsip/transport_udp_test.c +++ b/pjsip/src/test-pjsip/transport_udp_test.c @@ -21,6 +21,8 @@ #include <pjsip_core.h> #include <pjlib.h> +#define THIS_FILE "transport_udp_test.c" + /* * UDP transport test. @@ -32,7 +34,7 @@ int transport_udp_test(void) pj_sockaddr_in addr, rem_addr; pj_str_t s; pj_status_t status; - int i; + int i, pkt_lost; pj_sockaddr_in_init(&addr, NULL, TEST_UDP_PORT); @@ -84,10 +86,14 @@ int transport_udp_test(void) /* Multi-threaded round-trip test. */ status = transport_rt_test(PJSIP_TRANSPORT_UDP, tp, - "sip:alice@127.0.0.1:"TEST_UDP_PORT_STR); + "sip:alice@127.0.0.1:"TEST_UDP_PORT_STR, + &pkt_lost); if (status != 0) return status; + if (pkt_lost != 0) + PJ_LOG(3,(THIS_FILE, " note: %d packet(s) was lost", pkt_lost)); + /* Check again that reference counter is 1. */ if (pj_atomic_get(udp_tp->ref_cnt) != 1) return -80; @@ -100,6 +106,9 @@ int transport_udp_test(void) if (status != PJ_SUCCESS) return -90; + /* Flush events. */ + PJ_LOG(3,(THIS_FILE, " Flushing events, 1 second...")); + flush_events(1000); /* Done */ return 0; diff --git a/pjsip/src/test-pjsip/tsx_basic_test.c b/pjsip/src/test-pjsip/tsx_basic_test.c new file mode 100644 index 00000000..1db86f8d --- /dev/null +++ b/pjsip/src/test-pjsip/tsx_basic_test.c @@ -0,0 +1,147 @@ +/* $Id$ */ +/* + * Copyright (C) 2003-2006 Benny Prijono <benny@prijono.org> + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + */ + +#include "test.h" +#include <pjsip_core.h> +#include <pjlib.h> + +#define THIS_FILE "tsx_basic_test.c" + +/* Test transaction layer. */ +static int tsx_layer_test(void) +{ + pj_str_t target, from, tsx_key; + pjsip_tx_data *tdata; + pjsip_transaction *tsx, *found; + pj_status_t status; + + PJ_LOG(3,(THIS_FILE, " transaction layer test")); + + target = pj_str("sip:alice@localhost"); + from = pj_str("sip:bob@localhost"); + + status = pjsip_endpt_create_request(endpt, &pjsip_invite_method, &target, + &from, &target, NULL, NULL, -1, NULL, + &tdata); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to create request", status); + return -110; + } + + status = pjsip_tsx_create_uac(NULL, tdata, &tsx); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to create transaction", status); + return -120; + } + + pj_strdup(tdata->pool, &tsx_key, &tsx->transaction_key); + + found = pjsip_tsx_layer_find_tsx(&tsx_key, PJ_FALSE); + if (found != tsx) { + return -130; + } + + pjsip_tsx_terminate(tsx, PJSIP_SC_REQUEST_TERMINATED); + flush_events(500); + + if (pjsip_tx_data_dec_ref(tdata) != PJSIP_EBUFDESTROYED) { + return -140; + } + + return 0; +} + +/* Double terminate test. */ +static int double_terminate(void) +{ + pj_str_t target, from, tsx_key; + pjsip_tx_data *tdata; + pjsip_transaction *tsx; + pj_status_t status; + + PJ_LOG(3,(THIS_FILE, " double terminate test")); + + target = pj_str("sip:alice@localhost;transport=loop-dgram"); + from = pj_str("sip:bob@localhost"); + + /* Create request. */ + status = pjsip_endpt_create_request(endpt, &pjsip_invite_method, &target, + &from, &target, NULL, NULL, -1, NULL, + &tdata); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to create request", status); + return -10; + } + + /* Create transaction. */ + status = pjsip_tsx_create_uac(NULL, tdata, &tsx); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to create transaction", status); + return -20; + } + + /* Save transaction key for later. */ + pj_strdup_with_null(tdata->pool, &tsx_key, &tsx->transaction_key); + + /* Add reference to transmit buffer (tsx_send_msg() will dec txdata). */ + pjsip_tx_data_add_ref(tdata); + + /* Send message to start timeout timer. */ + status = pjsip_tsx_send_msg(tsx, NULL); + + /* Terminate transaction. */ + status = pjsip_tsx_terminate(tsx, PJSIP_SC_REQUEST_TERMINATED); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to terminate transaction", status); + return -30; + } + + tsx = pjsip_tsx_layer_find_tsx(&tsx_key, PJ_TRUE); + if (tsx) { + /* Terminate transaction again. */ + pjsip_tsx_terminate(tsx, PJSIP_SC_REQUEST_TERMINATED); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to terminate transaction", status); + return -40; + } + pj_mutex_unlock(tsx->mutex); + } + + flush_events(500); + if (pjsip_tx_data_dec_ref(tdata) != PJSIP_EBUFDESTROYED) { + return -50; + } + + return PJ_SUCCESS; +} + +int tsx_basic_test(void) +{ + int status; + + status = tsx_layer_test(); + if (status != 0) + return status; + + status = double_terminate(); + if (status != 0) + return status; + + return 0; +} diff --git a/pjsip/src/test-pjsip/tsx_uac_test.c b/pjsip/src/test-pjsip/tsx_uac_test.c index 24af41e9..cf40e5d5 100644 --- a/pjsip/src/test-pjsip/tsx_uac_test.c +++ b/pjsip/src/test-pjsip/tsx_uac_test.c @@ -21,17 +21,77 @@ #include <pjsip_core.h> #include <pjlib.h> +#define THIS_FILE "tsx_uac_test.c" + + /***************************************************************************** ** - ** UAC basic retransmission and timeout test. + ** UAC tests. ** - ** This will test the retransmission of the UAC transaction. Remote will not - ** answer the transaction, so the transaction should fail. + ** This file performs various tests for UAC transactions. Each test will have + ** a different Via branch param so that message receiver module and + ** transaction user module can identify which test is being carried out. + ** + ** TEST1_BRANCH_ID + ** Perform basic retransmission and timeout test. Message receiver will + ** verify that retransmission is received at correct time. + ** This test verifies the following requirements: + ** - retransmit timer doubles for INVITE + ** - retransmit timer doubles and caps off for non-INVITE + ** - retransmit timer timer is precise + ** - correct timeout and retransmission count + ** Requirements not tested: + ** - retransmit timer only starts after resolving has completed. + ** + ** TEST2_BRANCH_ID + ** Test scenario where resolver is unable to resolve destination host. + ** + ** TEST3_BRANCH_ID + ** Test scenario where transaction is terminated while resolver is still + ** running. + ** + ** TEST4_BRANCH_ID + ** Test scenario where transport failed after several retransmissions. + ** + ** TEST5_BRANCH_ID + ** Test scenario where transaction is terminated by user after several + ** retransmissions. ** + ** TEST6_BRANCH_ID + ** Test successfull non-INVITE transaction. + ** It tests the following requirements: + ** - transaction correctly moves to COMPLETED state. + ** - retransmission must cease. + ** - tx_data must be maintained until state is terminated. + ** + ** TEST7_BRANCH_ID + ** Test successfull non-INVITE transaction, with provisional response. + ** + ** TEST8_BRANCH_ID + ** Test failed INVITE transaction (e.g. ACK must be received) + ** + ** TEST9_BRANCH_ID + ** Test failed INVITE transaction with provisional response. + ** + ** ***************************************************************************** */ -static char *CALL_ID1 = "UAC-Tsx-Basic-Test1"; +static char *TEST1_BRANCH_ID = PJSIP_RFC3261_BRANCH_ID "-Test1"; +static char *TEST2_BRANCH_ID = PJSIP_RFC3261_BRANCH_ID "-Test2"; +static char *TEST3_BRANCH_ID = PJSIP_RFC3261_BRANCH_ID "-Test3"; +static char *TEST4_BRANCH_ID = PJSIP_RFC3261_BRANCH_ID "-Test4"; +static char *TEST5_BRANCH_ID = PJSIP_RFC3261_BRANCH_ID "-Test5"; +static char *TEST6_BRANCH_ID = PJSIP_RFC3261_BRANCH_ID "-Test6"; +static char *TEST7_BRANCH_ID = PJSIP_RFC3261_BRANCH_ID "-Test7"; +static char *TEST8_BRANCH_ID = PJSIP_RFC3261_BRANCH_ID "-Test8"; +static char *TEST9_BRANCH_ID = PJSIP_RFC3261_BRANCH_ID "-Test9"; + +#define TEST1_ALLOWED_DIFF (150) +#define TEST4_RETRANSMIT_CNT 3 +#define TEST5_RETRANSMIT_CNT 3 + + static void tsx_user_on_tsx_state(pjsip_transaction *tsx, pjsip_event *e); static pj_bool_t msg_receiver_on_rx_request(pjsip_rx_data *rdata); @@ -51,6 +111,8 @@ static pjsip_module tsx_user = NULL, /* unload() */ NULL, /* on_rx_request() */ NULL, /* on_rx_response() */ + NULL, /* on_tx_request() */ + NULL, /* on_tx_response() */ &tsx_user_on_tsx_state, /* on_tsx_state() */ }; @@ -70,39 +132,205 @@ static pjsip_module msg_receiver = NULL, /* unload() */ &msg_receiver_on_rx_request, /* on_rx_request() */ NULL, /* on_rx_response() */ + NULL, /* on_tx_request() */ + NULL, /* on_tx_response() */ NULL, /* on_tsx_state() */ }; -/* Static vars. */ +/* Static vars, which will be reset on each test. */ static int recv_count; static pj_time_val recv_last; static pj_bool_t test_complete; +/* Loop transport instance. */ +static pjsip_transport *loop; + +/* + * This is the handler to receive state changed notification from the + * transaction. It is used to verify that the transaction behaves according + * to the test scenario. + */ static void tsx_user_on_tsx_state(pjsip_transaction *tsx, pjsip_event *e) { - if (tsx->state == PJSIP_TSX_STATE_TERMINATED && test_complete==0) - test_complete = 1; + if (pj_strcmp2(&tsx->branch, TEST1_BRANCH_ID)==0) { + /* + * Transaction with TEST1_BRANCH_ID should terminate with transaction + * timeout status. + */ + if (tsx->state == PJSIP_TSX_STATE_TERMINATED) { + + if (test_complete == 0) + test_complete = 1; + + /* Test the status code. */ + if (tsx->status_code != PJSIP_SC_TSX_TIMEOUT) { + PJ_LOG(3,(THIS_FILE, + " error: status code is %d instead of %d", + tsx->status_code, PJSIP_SC_TSX_TIMEOUT)); + test_complete = -710; + } + } + + } else if (pj_strcmp2(&tsx->branch, TEST2_BRANCH_ID)==0) { + /* + * Transaction with TEST2_BRANCH_ID should terminate with transport error. + */ + if (tsx->state == PJSIP_TSX_STATE_TERMINATED) { + + /* Test the status code. */ + if (tsx->status_code != PJSIP_SC_TSX_TRANSPORT_ERROR) { + PJ_LOG(3,(THIS_FILE, + " error: status code is %d instead of %d", + tsx->status_code, PJSIP_SC_TSX_TRANSPORT_ERROR)); + test_complete = -720; + } + + if (test_complete == 0) + test_complete = 1; + } + + } else if (pj_strcmp2(&tsx->branch, TEST3_BRANCH_ID)==0) { + /* + * This test terminates the transaction while resolver is still + * running. + */ + if (tsx->state == PJSIP_TSX_STATE_CALLING) { + + /* Terminate the transaction. */ + pjsip_tsx_terminate(tsx, PJSIP_SC_REQUEST_TERMINATED); + + } else if (tsx->state == PJSIP_TSX_STATE_TERMINATED) { + + /* Check if status code is correct. */ + if (tsx->status_code != PJSIP_SC_REQUEST_TERMINATED) { + PJ_LOG(3,(THIS_FILE, + " error: status code is %d instead of %d", + tsx->status_code, PJSIP_SC_REQUEST_TERMINATED)); + test_complete = -730; + } + + if (test_complete == 0) + test_complete = 1; + + } + + } else if (pj_strcmp2(&tsx->branch, TEST4_BRANCH_ID)==0) { + /* + * This test simulates transport failure after several + * retransmissions. + */ + if (tsx->state == PJSIP_TSX_STATE_TERMINATED) { + + /* Status code must be transport error. */ + if (tsx->status_code != PJSIP_SC_TSX_TRANSPORT_ERROR) { + PJ_LOG(3,(THIS_FILE, + " error: status code is %d instead of %d", + tsx->status_code, PJSIP_SC_TSX_TRANSPORT_ERROR)); + test_complete = -730; + } + + /* Must have correct retransmission count. */ + if (tsx->retransmit_count != TEST4_RETRANSMIT_CNT) { + PJ_LOG(3,(THIS_FILE, + " error: retransmit cnt is %d instead of %d", + tsx->retransmit_count, TEST4_RETRANSMIT_CNT)); + test_complete = -731; + } + + if (test_complete == 0) + test_complete = 1; + } + + + } else if (pj_strcmp2(&tsx->branch, TEST5_BRANCH_ID)==0) { + /* + * This test simulates transport failure after several + * retransmissions. + */ + if (tsx->state == PJSIP_TSX_STATE_TERMINATED) { + + /* Status code must be PJSIP_SC_REQUEST_TERMINATED. */ + if (tsx->status_code != PJSIP_SC_REQUEST_TERMINATED) { + PJ_LOG(3,(THIS_FILE, + " error: status code is %d instead of %d", + tsx->status_code, PJSIP_SC_REQUEST_TERMINATED)); + test_complete = -733; + } + + /* Must have correct retransmission count. */ + if (tsx->retransmit_count != TEST5_RETRANSMIT_CNT) { + PJ_LOG(3,(THIS_FILE, + " error: retransmit cnt is %d instead of %d", + tsx->retransmit_count, TEST5_RETRANSMIT_CNT)); + test_complete = -734; + } + + if (test_complete == 0) + test_complete = 1; + } + + + } else if (pj_strcmp2(&tsx->branch, TEST6_BRANCH_ID)==0) { + /* + * Successfull non-INVITE transaction. + */ + if (tsx->state == PJSIP_TSX_STATE_COMPLETED) { + + /* Status code must be 202. */ + if (tsx->status_code != 202) { + PJ_LOG(3,(THIS_FILE, + " error: status code is %d instead of %d", + tsx->status_code, 202)); + test_complete = -736; + } + + /* Must have correct retransmission count. */ + if (tsx->retransmit_count != 0) { + PJ_LOG(3,(THIS_FILE, + " error: retransmit cnt is %d instead of %d", + tsx->retransmit_count, 0)); + test_complete = -737; + } + + /* Must still keep last_tx */ + if (tsx->last_tx == NULL) { + PJ_LOG(3,(THIS_FILE, + " error: transaction lost last_tx")); + test_complete = -738; + } + + if (test_complete == 0) { + test_complete = 1; + pjsip_tsx_terminate(tsx, 202); + } + } + } } #define DIFF(a,b) ((a<b) ? (b-a) : (a-b)) +/* + * This is the handler to receive message for this test. It is used to + * control and verify the behavior of the message transmitted by the + * transaction. + */ static pj_bool_t msg_receiver_on_rx_request(pjsip_rx_data *rdata) { - if (pj_strcmp2(&rdata->msg_info.call_id, CALL_ID1) == 0) { + if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST1_BRANCH_ID) == 0) { /* - * The CALL_ID1 test performs the verifications for transaction + * The TEST1_BRANCH_ID test performs the verifications for transaction * retransmission mechanism. It will not answer the incoming request * with any response. */ pjsip_msg *msg = rdata->msg_info.msg; - PJ_LOG(4,("", " received request")); + PJ_LOG(4,(THIS_FILE, " received request")); /* Only wants to take INVITE or OPTIONS method. */ if (msg->line.req.method.id != PJSIP_INVITE_METHOD && msg->line.req.method.id != PJSIP_OPTIONS_METHOD) { - PJ_LOG(3,("", " error: received unexpected method %.*s", + PJ_LOG(3,(THIS_FILE, " error: received unexpected method %.*s", msg->line.req.method.name.slen, msg->line.req.method.name.ptr)); test_complete = -600; @@ -111,12 +339,15 @@ static pj_bool_t msg_receiver_on_rx_request(pjsip_rx_data *rdata) if (recv_count == 0) { recv_count++; - pj_gettimeofday(&recv_last); + //pj_gettimeofday(&recv_last); + recv_last = rdata->pkt_info.timestamp; } else { pj_time_val now; unsigned msec_expected, msec_elapsed; + int max_received; - pj_gettimeofday(&now); + //pj_gettimeofday(&now); + now = rdata->pkt_info.timestamp; PJ_TIME_VAL_SUB(now, recv_last); msec_elapsed = now.sec*1000 + now.msec; @@ -126,63 +357,165 @@ static pj_bool_t msg_receiver_on_rx_request(pjsip_rx_data *rdata) if (msg->line.req.method.id != PJSIP_INVITE_METHOD) { if (msec_expected > PJSIP_T2_TIMEOUT) msec_expected = PJSIP_T2_TIMEOUT; + max_received = 11; + } else { + max_received = 7; } - if (DIFF(msec_expected, msec_elapsed) > 100) { - PJ_LOG(3,(""," error: expecting %d-th retransmission in %d " - "ms, received in %d ms", - recv_count-1, msec_expected, msec_elapsed)); + if (DIFF(msec_expected, msec_elapsed) > TEST1_ALLOWED_DIFF) { + PJ_LOG(3,(THIS_FILE, + " error: expecting retransmission no. %d in %d " + "ms, received in %d ms", + recv_count-1, msec_expected, msec_elapsed)); test_complete = -610; } - if (recv_count > 7) { - PJ_LOG(3,("", " error: too many messages (%d) received", - recv_count)); + + if (recv_count > max_received) { + PJ_LOG(3,(THIS_FILE, + " error: too many messages (%d) received", + recv_count)); test_complete = -620; } - pj_gettimeofday(&recv_last); + //pj_gettimeofday(&recv_last); + recv_last = rdata->pkt_info.timestamp; + } + return PJ_TRUE; + + } else + if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST4_BRANCH_ID) == 0) { + /* + * The TEST4_BRANCH_ID test simulates transport failure after several + * retransmissions. + */ + recv_count++; + + if (recv_count == TEST4_RETRANSMIT_CNT) { + /* Simulate transport failure. */ + pjsip_loop_set_failure(loop, 2, NULL); + + } else if (recv_count > TEST4_RETRANSMIT_CNT) { + PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!", + recv_count)); + test_complete = -631; + } + + return PJ_TRUE; + + + } else + if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST5_BRANCH_ID) == 0) { + /* + * The TEST5_BRANCH_ID test simulates user terminating the transaction + * after several retransmissions. + */ + recv_count++; + + if (recv_count == TEST5_RETRANSMIT_CNT+1) { + pj_str_t key; + pjsip_transaction *tsx; + + pjsip_tsx_create_key( rdata->tp_info.pool, &key, PJSIP_ROLE_UAC, + &rdata->msg_info.msg->line.req.method, rdata); + tsx = pjsip_tsx_layer_find_tsx(&key, PJ_TRUE); + if (tsx) { + pjsip_tsx_terminate(tsx, PJSIP_SC_REQUEST_TERMINATED); + pj_mutex_unlock(tsx->mutex); + } else { + PJ_LOG(3,(THIS_FILE, " error: uac transaction not found!")); + test_complete = -633; + } + + } else if (recv_count > TEST5_RETRANSMIT_CNT+1) { + PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!", + recv_count)); + test_complete = -634; + } + + return PJ_TRUE; + + } else + if (pj_strcmp2(&rdata->msg_info.via->branch_param, TEST6_BRANCH_ID) == 0) { + /* + * The TEST5_BRANCH_ID test successfull non-INVITE transaction. + */ + pjsip_tx_data *tdata; + pjsip_response_addr res_addr; + pj_status_t status; + + recv_count++; + + if (recv_count > 1) { + PJ_LOG(3,(THIS_FILE," error: not expecting %d-th packet!", + recv_count)); + test_complete = -635; + } + + status = pjsip_endpt_create_response(endpt, rdata, 202, NULL, &tdata); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to create response", status); + test_complete = -636; + } + + status = pjsip_get_response_addr(tdata->pool, rdata, &res_addr); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to get response addr", status); + test_complete = -637; } + + status = pjsip_endpt_send_response(endpt, &res_addr, tdata, NULL,NULL); + if (status != PJ_SUCCESS) { + app_perror(" error: unable to send response", status); + test_complete = -638; + pjsip_tx_data_dec_ref(tdata); + } + return PJ_TRUE; } + return PJ_FALSE; } -/***************************************************************************** - ** - ** UAC basic retransmission and timeout test. - ** - ** This will test the retransmission of the UAC transaction. Remote will not - ** answer the transaction, so the transaction should fail. The Call-ID - ** CALL_ID1 will be used for this test. - ** - ***************************************************************************** +/* + * The generic test framework, used by most of the tests. */ -static int tsx_uac_retransmit_test(const pjsip_method *method) +static int perform_tsx_test(int dummy, char *target_uri, char *from_uri, + char *branch_param, int test_time, + const pjsip_method *method) { pjsip_tx_data *tdata; pjsip_transaction *tsx; - char buf[80]; - pj_str_t target, from, call_id, tsx_key; + pj_str_t target, from, tsx_key; + pjsip_via_hdr *via; pj_time_val timeout; pj_status_t status; - PJ_LOG(3,("", " basic uac retransmission and timeout test")); + PJ_LOG(3,(THIS_FILE, + " please standby, this will take at most %d seconds..", + test_time)); - pj_sprintf(buf, "sip:alice@127.0.0.1:%d", TEST_UDP_PORT); - target = pj_str(buf); - from = pj_str("sip:bob@127.0.0.1"); - call_id = pj_str(CALL_ID1); + /* Reset test. */ + recv_count = 0; + test_complete = 0; + + /* Init headers. */ + target = pj_str(target_uri); + from = pj_str(from_uri); /* Create request. */ status = pjsip_endpt_create_request( endpt, method, &target, - &from, &target, NULL, &call_id, -1, + &from, &target, NULL, NULL, -1, NULL, &tdata); if (status != PJ_SUCCESS) { app_perror(" Error: unable to create request", status); - return -500; + return -100; } + /* Set the branch param for test 1. */ + via = pjsip_msg_find_hdr(tdata->msg, PJSIP_H_VIA, NULL); + via->branch_param = pj_str(branch_param); + /* Add additional reference to tdata to prevent transaction from * deleting it. */ @@ -192,7 +525,8 @@ static int tsx_uac_retransmit_test(const pjsip_method *method) status = pjsip_tsx_create_uac( &tsx_user, tdata, &tsx); if (status != PJ_SUCCESS) { app_perror(" Error: unable to create UAC transaction", status); - return -510; + pjsip_tx_data_dec_ref(tdata); + return -110; } /* Get transaction key. */ @@ -200,42 +534,65 @@ static int tsx_uac_retransmit_test(const pjsip_method *method) /* Send the message. */ status = pjsip_tsx_send_msg(tsx, NULL); - if (status != PJ_SUCCESS) { - app_perror(" Error: unable to send request", status); - return -520; - } + // Ignore send result. Some tests do deliberately triggers error + // when sending message. + //if (status != PJ_SUCCESS) { + // app_perror(" Error: unable to send request", status); + // pjsip_tx_data_dec_ref(tdata); + // return -120; + //} + /* Set test completion time. */ pj_gettimeofday(&timeout); - timeout.sec += 33; + timeout.sec += test_time; /* Wait until test complete. */ while (!test_complete) { - pj_time_val now; + pj_time_val now, poll_delay = {0, 10}; - pjsip_endpt_handle_events(endpt, NULL); + pjsip_endpt_handle_events(endpt, &poll_delay); pj_gettimeofday(&now); if (now.sec > timeout.sec) { - PJ_LOG(3,("", " Error: test has timed out")); - return -530; + PJ_LOG(3,(THIS_FILE, " Error: test has timed out")); + pjsip_tx_data_dec_ref(tdata); + return -130; } } - if (status < 0) + if (status < 0) { + pjsip_tx_data_dec_ref(tdata); return status; + } + + if (test_complete < 0) { + tsx = pjsip_tsx_layer_find_tsx(&tsx_key, PJ_TRUE); + if (tsx) { + pjsip_tsx_terminate(tsx, PJSIP_SC_REQUEST_TERMINATED); + pj_mutex_unlock(tsx->mutex); + flush_events(1000); + } + pjsip_tx_data_dec_ref(tdata); + return test_complete; + } + + /* Allow transaction to destroy itself */ + flush_events(500); /* Make sure transaction has been destroyed. */ if (pjsip_tsx_layer_find_tsx(&tsx_key, PJ_FALSE) != NULL) { - PJ_LOG(3,("", " Error: transaction has not been destroyed")); - return -540; + PJ_LOG(3,(THIS_FILE, " Error: transaction has not been destroyed")); + pjsip_tx_data_dec_ref(tdata); + return -140; } /* Check tdata reference counter. */ if (pj_atomic_get(tdata->ref_cnt) != 1) { - PJ_LOG(3,("", " Error: tdata reference counter is %d", + PJ_LOG(3,(THIS_FILE, " Error: tdata reference counter is %d", pj_atomic_get(tdata->ref_cnt))); - return -550; + pjsip_tx_data_dec_ref(tdata); + return -150; } /* Destroy txdata */ @@ -246,38 +603,280 @@ static int tsx_uac_retransmit_test(const pjsip_method *method) /***************************************************************************** ** - ** UAC Transaction Test. + ** TEST1_BRANCH_ID: UAC basic retransmission and timeout test. + ** + ** This will test the retransmission of the UAC transaction. Remote will not + ** answer the transaction, so the transaction should fail. The Via branch prm + ** TEST1_BRANCH_ID will be used for this test. ** ***************************************************************************** */ -int tsx_uac_test(void) +static int tsx_uac_retransmit_test(void) { - pj_sockaddr_in addr; - pj_str_t tmp; - pjsip_transport *tp; + int status, enabled; + int i; + struct { + const pjsip_method *method; + unsigned delay; + } sub_test[] = + { + { &pjsip_invite_method, 0}, + { &pjsip_invite_method, TEST1_ALLOWED_DIFF*2}, + { &pjsip_options_method, 0}, + { &pjsip_options_method, TEST1_ALLOWED_DIFF*2} + }; + + PJ_LOG(3,(THIS_FILE, " test1: basic uac retransmit and timeout test")); + + + /* For this test. message printing shound be disabled because it makes + * incorrect timing. + */ + enabled = msg_logger_set_enabled(0); + + for (i=0; i<PJ_ARRAY_SIZE(sub_test); ++i) { + + PJ_LOG(3,(THIS_FILE, + " variant %c: %s with %d ms network delay", + ('a' + i), + sub_test[i].method->name.ptr, + sub_test[i].delay)); + + /* Configure transport */ + pjsip_loop_set_failure(loop, 0, NULL); + pjsip_loop_set_recv_delay(loop, sub_test[i].delay, NULL); + + /* Do the test. */ + status = perform_tsx_test(-500, "sip:bob@127.0.0.1;transport=loop-dgram", + "sip:alice@127.0.0.1;transport=loop-dgram", + TEST1_BRANCH_ID, + 35, sub_test[i].method); + if (status != 0) + break; + } + + /* Restore transport. */ + pjsip_loop_set_recv_delay(loop, 0, NULL); + + /* Restore msg logger. */ + msg_logger_set_enabled(enabled); + + /* Done. */ + return status; +} + +/***************************************************************************** + ** + ** TEST2_BRANCH_ID: UAC resolve error test. + ** + ** Test the scenario where destination host is unresolvable. There are + ** two variants: + ** (a) resolver returns immediate error + ** (b) resolver returns error via the callback. + ** + ***************************************************************************** + */ +static int tsx_resolve_error_test(void) +{ + int status; + + PJ_LOG(3,(THIS_FILE, " test2: resolve error test")); + + /* + * Variant (a): immediate resolve error. + */ + PJ_LOG(3,(THIS_FILE, " variant a: immediate resolving error")); + + status = perform_tsx_test(-800, + "sip:bob@unresolved-host;transport=loop-dgram", + "sip:alice@127.0.0.1;transport=loop-dgram", + TEST2_BRANCH_ID, 10, + &pjsip_options_method); + if (status != 0) + return status; + + /* + * Variant (b): error via callback. + */ + PJ_LOG(3,(THIS_FILE, " variant b: error via callback")); + + /* Set loop transport to return delayed error. */ + pjsip_loop_set_failure(loop, 2, NULL); + pjsip_loop_set_send_callback_delay(loop, 10, NULL); + + status = perform_tsx_test(-800, "sip:bob@127.0.0.1;transport=loop-dgram", + "sip:alice@127.0.0.1;transport=loop-dgram", + TEST2_BRANCH_ID, 2, + &pjsip_options_method); + if (status != 0) + return status; + + /* Restore loop transport settings. */ + pjsip_loop_set_failure(loop, 0, NULL); + pjsip_loop_set_send_callback_delay(loop, 0, NULL); + + return status; +} + + +/***************************************************************************** + ** + ** TEST3_BRANCH_ID: UAC terminate while resolving test. + ** + ** Terminate the transaction while resolver is still running. + ** + ***************************************************************************** + */ +static int tsx_terminate_resolving_test(void) +{ + unsigned prev_delay; pj_status_t status; - pj_sockaddr_in_init(&addr, pj_cstr(&tmp, "127.0.0.1"), TEST_UDP_PORT); + PJ_LOG(3,(THIS_FILE, " test3: terminate while resolving test")); - /* Start UDP transport if necessary. */ - if (pjsip_endpt_acquire_transport(endpt, PJSIP_TRANSPORT_UDP, &addr, - sizeof(addr), &tp) != PJ_SUCCESS) - { - addr.sin_addr.s_addr = 0; - status = pjsip_udp_transport_start( endpt, &addr, NULL, 1, NULL); - if (status != PJ_SUCCESS) { - app_perror(" Error: unable to start UDP transport", status); - return -10; - } - } else { - pjsip_transport_dec_ref(tp); + /* Configure transport delay. */ + pjsip_loop_set_send_callback_delay(loop, 100, &prev_delay); + + /* Start the test. */ + status = perform_tsx_test(-900, "sip:127.0.0.1;transport=loop-dgram", + "sip:127.0.0.1;transport=loop-dgram", + TEST3_BRANCH_ID, 2, &pjsip_options_method); + + /* Restore delay. */ + pjsip_loop_set_send_callback_delay(loop, prev_delay, NULL); + + return status; +} + + +/***************************************************************************** + ** + ** TEST4_BRANCH_ID: Transport failed after several retransmissions + ** + ** There are two variants of this test: (a) failure occurs immediately when + ** transaction calls pjsip_transport_send() or (b) failure is reported via + ** transport callback. + ** + ***************************************************************************** + */ +static int tsx_retransmit_fail_test(void) +{ + int i; + unsigned delay[] = {0, 10}; + pj_status_t status; + + PJ_LOG(3,(THIS_FILE, + " test4: transport fails after several retransmissions test")); + + + for (i=0; i<PJ_ARRAY_SIZE(delay); ++i) { + + PJ_LOG(3,(THIS_FILE, + " variant %c: transport delay %d ms", ('a'+i), delay[i])); + + /* Configure transport delay. */ + pjsip_loop_set_send_callback_delay(loop, delay[i], NULL); + + /* Restore transport failure mode. */ + pjsip_loop_set_failure(loop, 0, 0); + + /* Start the test. */ + status = perform_tsx_test(-1000, "sip:127.0.0.1;transport=loop-dgram", + "sip:127.0.0.1;transport=loop-dgram", + TEST4_BRANCH_ID, 6, &pjsip_options_method); + + if (status != 0) + break; + + } + + /* Restore delay. */ + pjsip_loop_set_send_callback_delay(loop, 0, NULL); + + /* Restore transport failure mode. */ + pjsip_loop_set_failure(loop, 0, 0); + + return status; +} + + +/***************************************************************************** + ** + ** TEST5_BRANCH_ID: Terminate transaction after several retransmissions + ** + ***************************************************************************** + */ +static int tsx_terminate_after_retransmit_test(void) +{ + int status; + + PJ_LOG(3,(THIS_FILE, " test5: terminate after retransmissions")); + + /* Do the test. */ + status = perform_tsx_test(-1100, "sip:bob@127.0.0.1;transport=loop-dgram", + "sip:alice@127.0.0.1;transport=loop-dgram", + TEST5_BRANCH_ID, + 6, &pjsip_options_method); + + /* Done. */ + return status; +} + + +/***************************************************************************** + ** + ** TEST6_BRANCH_ID: Successfull non-invite transaction + ** + ***************************************************************************** + */ +static int tsx_successfull_non_invite_test(void) +{ + int i, status; + unsigned delay[] = { 1, 200 }; + + PJ_LOG(3,(THIS_FILE, " test6: successfull non-invite transaction")); + + /* Do the test. */ + for (i=0; i<PJ_ARRAY_SIZE(delay); ++i) { + + PJ_LOG(3,(THIS_FILE, " variant %c: with %d ms transport delay", + ('a'+i), delay[i])); + + pjsip_loop_set_delay(loop, delay[i]); + + status = perform_tsx_test(-1200, + "sip:bob@127.0.0.1;transport=loop-dgram", + "sip:alice@127.0.0.1;transport=loop-dgram", + TEST6_BRANCH_ID, + 2, &pjsip_options_method); + if (status != 0) + return status; } - /* Start transaction layer module. */ - status = pjsip_tsx_layer_init(endpt); + pjsip_loop_set_delay(loop, 0); + + /* Done. */ + return status; +} + + +/***************************************************************************** + ** + ** UAC Transaction Test. + ** + ***************************************************************************** + */ +int tsx_uac_test(void) +{ + pj_sockaddr_in addr; + pj_status_t status; + + /* Check if loop transport is configured. */ + status = pjsip_endpt_acquire_transport(endpt, PJSIP_TRANSPORT_LOOP_DGRAM, + &addr, sizeof(addr), &loop); if (status != PJ_SUCCESS) { - app_perror(" Error initializing transaction module", status); - return -20; + PJ_LOG(3,(THIS_FILE, " Error: loop transport is not configured!")); + return -10; } /* Register modules. */ @@ -289,18 +888,43 @@ int tsx_uac_test(void) status = pjsip_endpt_register_module(endpt, &msg_receiver); if (status != PJ_SUCCESS) { app_perror(" Error: unable to register module", status); - return -30; + return -40; } - /* Basic retransmit and timeout test for INVITE. */ - status = tsx_uac_retransmit_test(&pjsip_invite_method); +#if 0 + /* TEST1_BRANCH_ID: Basic retransmit and timeout test. */ + status = tsx_uac_retransmit_test(); + if (status != 0) + return status; + + /* TEST2_BRANCH_ID: Resolve error test. */ + status = tsx_resolve_error_test(); if (status != 0) return status; - /* Basic retransmit and timeout test for non-INVITE. */ - status = tsx_uac_retransmit_test(&pjsip_options_method); + /* TEST3_BRANCH_ID: UAC terminate while resolving test. */ + status = tsx_terminate_resolving_test(); if (status != 0) return status; + /* TEST4_BRANCH_ID: Transport failed after several retransmissions */ + status = tsx_retransmit_fail_test(); + if (status != 0) + return status; + + /* TEST5_BRANCH_ID: Terminate transaction after several retransmissions */ + status = tsx_terminate_after_retransmit_test(); + if (status != 0) + return status; +#endif + + /* TEST6_BRANCH_ID: Successfull non-invite transaction */ + status = tsx_successfull_non_invite_test(); + if (status != 0) + return status; + + + pjsip_transport_dec_ref(loop); return 0; } + diff --git a/pjsip/src/test-pjsip/txdata_test.c b/pjsip/src/test-pjsip/txdata_test.c index 08cad024..b740c6fe 100644 --- a/pjsip/src/test-pjsip/txdata_test.c +++ b/pjsip/src/test-pjsip/txdata_test.c @@ -23,6 +23,9 @@ #define HFIND(msg,h,H) ((pjsip_##h##_hdr*) pjsip_msg_find_hdr(msg, PJSIP_H_##H, NULL)) +#define THIS_FILE "txdata_test.c" + + /* * This tests various core message creation functions. */ @@ -50,12 +53,12 @@ int txdata_test(void) /* Buffer must be invalid. */ if (pjsip_tx_data_is_valid(invite) != 0) { - PJ_LOG(3,("", " error: buffer must be invalid")); + PJ_LOG(3,(THIS_FILE, " error: buffer must be invalid")); return -14; } /* Reference counter must be set to 1. */ if (pj_atomic_get(invite->ref_cnt) != 1) { - PJ_LOG(3,("", " error: invalid reference counter")); + PJ_LOG(3,(THIS_FILE, " error: invalid reference counter")); return -15; } /* Check message type. */ @@ -102,12 +105,12 @@ int txdata_test(void) /* Buffer must be invalid. */ if (pjsip_tx_data_is_valid(invite2) != 0) { - PJ_LOG(3,("", " error: buffer must be invalid")); + PJ_LOG(3,(THIS_FILE, " error: buffer must be invalid")); return -34; } /* Reference counter must be set to 1. */ if (pj_atomic_get(invite2->ref_cnt) != 1) { - PJ_LOG(3,("", " error: invalid reference counter")); + PJ_LOG(3,(THIS_FILE, " error: invalid reference counter")); return -35; } /* Check message type. */ @@ -141,7 +144,7 @@ int txdata_test(void) /* Done checking invite2. We can delete this. */ if (pjsip_tx_data_dec_ref(invite2) != PJSIP_EBUFDESTROYED) { - PJ_LOG(3,("", " error: request buffer not destroyed!")); + PJ_LOG(3,(THIS_FILE, " error: request buffer not destroyed!")); return -49; } @@ -172,12 +175,12 @@ int txdata_test(void) /* Buffer must be invalid. */ if (pjsip_tx_data_is_valid(response) != 0) { - PJ_LOG(3,("", " error: buffer must be invalid")); + PJ_LOG(3,(THIS_FILE, " error: buffer must be invalid")); return -54; } /* Check reference counter. */ if (pj_atomic_get(response->ref_cnt) != 1) { - PJ_LOG(3,("", " error: invalid ref count in response")); + PJ_LOG(3,(THIS_FILE, " error: invalid ref count in response")); return -55; } /* Check message type. */ @@ -214,12 +217,12 @@ int txdata_test(void) /* Buffer must be invalid. */ if (pjsip_tx_data_is_valid(cancel) != 0) { - PJ_LOG(3,("", " error: buffer must be invalid")); + PJ_LOG(3,(THIS_FILE, " error: buffer must be invalid")); return -84; } /* Check reference counter. */ if (pj_atomic_get(cancel->ref_cnt) != 1) { - PJ_LOG(3,("", " error: invalid ref count in CANCEL request")); + PJ_LOG(3,(THIS_FILE, " error: invalid ref count in CANCEL request")); return -85; } /* Check message type. */ @@ -247,7 +250,7 @@ int txdata_test(void) /* Done checking CANCEL request. */ if (pjsip_tx_data_dec_ref(cancel) != PJSIP_EBUFDESTROYED) { - PJ_LOG(3,("", " error: response buffer not destroyed!")); + PJ_LOG(3,(THIS_FILE, " error: response buffer not destroyed!")); return -99; } @@ -259,17 +262,17 @@ int txdata_test(void) /* Create ACK request */ status = pjsip_endpt_create_ack( endpt, invite, &dummy_rdata, &ack ); if (status != PJ_SUCCESS) { - PJ_LOG(3,("", " error: unable to create ACK")); + PJ_LOG(3,(THIS_FILE, " error: unable to create ACK")); return -100; } /* Buffer must be invalid. */ if (pjsip_tx_data_is_valid(ack) != 0) { - PJ_LOG(3,("", " error: buffer must be invalid")); + PJ_LOG(3,(THIS_FILE, " error: buffer must be invalid")); return -104; } /* Check reference counter. */ if (pj_atomic_get(ack->ref_cnt) != 1) { - PJ_LOG(3,("", " error: invalid ref count in ACK request")); + PJ_LOG(3,(THIS_FILE, " error: invalid ref count in ACK request")); return -105; } /* Check message type. */ @@ -298,19 +301,19 @@ int txdata_test(void) /* Done checking invite message. */ if (pjsip_tx_data_dec_ref(invite) != PJSIP_EBUFDESTROYED) { - PJ_LOG(3,("", " error: response buffer not destroyed!")); + PJ_LOG(3,(THIS_FILE, " error: response buffer not destroyed!")); return -120; } /* Done checking response message. */ if (pjsip_tx_data_dec_ref(response) != PJSIP_EBUFDESTROYED) { - PJ_LOG(3,("", " error: response buffer not destroyed!")); + PJ_LOG(3,(THIS_FILE, " error: response buffer not destroyed!")); return -130; } /* Done checking ack message. */ if (pjsip_tx_data_dec_ref(ack) != PJSIP_EBUFDESTROYED) { - PJ_LOG(3,("", " error: response buffer not destroyed!")); + PJ_LOG(3,(THIS_FILE, " error: response buffer not destroyed!")); return -140; } diff --git a/pjsip/src/test-pjsip/uri_test.c b/pjsip/src/test-pjsip/uri_test.c index de9604bf..46edd66a 100644 --- a/pjsip/src/test-pjsip/uri_test.c +++ b/pjsip/src/test-pjsip/uri_test.c @@ -20,6 +20,8 @@ #include <pjsip_core.h> #include <pjlib.h> +#define THIS_FILE "uri_test.c" + #define ALPHANUM "abcdefghijklmnopqrstuvwxyz" \ "ABCDEFGHIJKLMNOPQRSTUVWXYZ" \ @@ -692,9 +694,9 @@ static pj_status_t do_uri_test(pj_pool_t *pool, struct uri_test *entry) */ status = entry->status==ERR_SYNTAX_ERR ? PJ_SUCCESS : -10; if (status != 0) { - PJ_LOG(3,("", " uri parse error!\n" - " uri='%s'\n", - entry->str)); + PJ_LOG(3,(THIS_FILE, " uri parse error!\n" + " uri='%s'\n", + entry->str)); } goto on_return; } @@ -738,10 +740,10 @@ static pj_status_t do_uri_test(pj_pool_t *pool, struct uri_test *entry) /* Not equal. See if this is the expected status. */ status = entry->status==ERR_NOT_EQUAL ? PJ_SUCCESS : -40; if (status != 0) { - PJ_LOG(3,("", " uri comparison mismatch, status=%d:\n" - " uri1='%s'\n" - " uri2='%s'", - status, s1.ptr, s2.ptr)); + PJ_LOG(3,(THIS_FILE, " uri comparison mismatch, status=%d:\n" + " uri1='%s'\n" + " uri2='%s'", + status, s1.ptr, s2.ptr)); } goto on_return; @@ -762,19 +764,19 @@ static pj_status_t do_uri_test(pj_pool_t *pool, struct uri_test *entry) if (entry->printed) { if (pj_strcmp2(&s1, entry->printed) != 0) { /* Not equal. */ - PJ_LOG(3,("", " uri print mismatch:\n" - " printed='%s'\n" - " expectd='%s'", - s1.ptr, entry->printed)); + PJ_LOG(3,(THIS_FILE, " uri print mismatch:\n" + " printed='%s'\n" + " expectd='%s'", + s1.ptr, entry->printed)); status = -60; } } else { if (pj_strcmp(&s1, &s2) != 0) { /* Not equal. */ - PJ_LOG(3,("", " uri print mismatch:\n" - " uri1='%s'\n" - " uri2='%s'", - s1.ptr, s2.ptr)); + PJ_LOG(3,(THIS_FILE, " uri print mismatch:\n" + " uri1='%s'\n" + " uri2='%s'", + s1.ptr, s2.ptr)); status = -70; } } @@ -794,19 +796,19 @@ int uri_test() zero.u32.hi = zero.u32.lo = 0; - PJ_LOG(3,("", " simple test")); + PJ_LOG(3,(THIS_FILE, " simple test")); pool = pjsip_endpt_create_pool(endpt, "", POOL_SIZE, POOL_SIZE); for (i=0; i<PJ_ARRAY_SIZE(uri_test_array); ++i) { status = do_uri_test(pool, &uri_test_array[i]); if (status != PJ_SUCCESS) { - PJ_LOG(3,("uri_test", " error %d when testing entry %d", + PJ_LOG(3,(THIS_FILE, " error %d when testing entry %d", status, i)); goto on_return; } } pjsip_endpt_release_pool(endpt, pool); - PJ_LOG(3,("", " benchmarking...")); + PJ_LOG(3,(THIS_FILE, " benchmarking...")); parse_len = print_len = cmp_len = 0; parse_time.u32.hi = parse_time.u32.lo = 0; print_time.u32.hi = print_time.u32.lo = 0; @@ -816,7 +818,7 @@ int uri_test() for (i=0; i<PJ_ARRAY_SIZE(uri_test_array); ++i) { status = do_uri_test(pool, &uri_test_array[i]); if (status != PJ_SUCCESS) { - PJ_LOG(3,("uri_test", " error %d when testing entry %d", + PJ_LOG(3,(THIS_FILE, " error %d when testing entry %d", status, i)); pjsip_endpt_release_pool(endpt, pool); goto on_return; @@ -834,10 +836,11 @@ int uri_test() pj_highprec_div(avg_parse, parse_len); avg_parse = 1000000 / avg_parse; - PJ_LOG(3,("", " %u.%u MB of urls parsed in %d.%03ds (avg=%d urls/sec)", - (unsigned)(parse_len/1000000), (unsigned)kbytes, - elapsed.sec, elapsed.msec, - (unsigned)avg_parse)); + PJ_LOG(3,(THIS_FILE, + " %u.%u MB of urls parsed in %d.%03ds (avg=%d urls/sec)", + (unsigned)(parse_len/1000000), (unsigned)kbytes, + elapsed.sec, elapsed.msec, + (unsigned)avg_parse)); kbytes = print_len; pj_highprec_mod(kbytes, 1000000); @@ -848,10 +851,11 @@ int uri_test() pj_highprec_div(avg_print, parse_len); avg_print = 1000000 / avg_print; - PJ_LOG(3,("", " %u.%u MB of urls printed in %d.%03ds (avg=%d urls/sec)", - (unsigned)(print_len/1000000), (unsigned)kbytes, - elapsed.sec, elapsed.msec, - (unsigned)avg_print)); + PJ_LOG(3,(THIS_FILE, + " %u.%u MB of urls printed in %d.%03ds (avg=%d urls/sec)", + (unsigned)(print_len/1000000), (unsigned)kbytes, + elapsed.sec, elapsed.msec, + (unsigned)avg_print)); kbytes = cmp_len; pj_highprec_mod(kbytes, 1000000); @@ -862,12 +866,13 @@ int uri_test() pj_highprec_div(avg_cmp, cmp_len); avg_cmp = 1000000 / avg_cmp; - PJ_LOG(3,("", " %u.%u MB of urls compared in %d.%03ds (avg=%d urls/sec)", - (unsigned)(cmp_len/1000000), (unsigned)kbytes, - elapsed.sec, elapsed.msec, - (unsigned)avg_cmp)); + PJ_LOG(3,(THIS_FILE, + " %u.%u MB of urls compared in %d.%03ds (avg=%d urls/sec)", + (unsigned)(cmp_len/1000000), (unsigned)kbytes, + elapsed.sec, elapsed.msec, + (unsigned)avg_cmp)); - PJ_LOG(3,("", " multithreaded test")); + PJ_LOG(3,(THIS_FILE, " multithreaded test")); on_return: |