[May 25 19:31:02] Asterisk 13.15.0 built by root @ testbed3.company.net on a x86_64 running Linux on 2017-05-09 21:36:47 UTC
[May 25 19:31:02] VERBOSE[69465] config.c: Parsing '/etc/asterisk/logger.conf': Found
[May 25 19:31:08] VERBOSE[69391] pbx_variables.c: Setting global variable 'SIPDOMAIN' to 'testbed3.company.net'
[May 25 19:31:08] VERBOSE[69495][C-00000002] pbx.c: Executing [424242@from-internal:1] Answer("PJSIP/109-00000002", "") in new stack
[May 25 19:31:08] VERBOSE[69495][C-00000002] pbx.c: Executing [424242@from-internal:2] Set("PJSIP/109-00000002", "CDR(cdr_application)=Call Queue") in new stack
[May 25 19:31:08] VERBOSE[69495][C-00000002] pbx.c: Executing [424242@from-internal:3] GotoIf("PJSIP/109-00000002", "0?keepDir") in new stack
[May 25 19:31:08] VERBOSE[69495][C-00000002] pbx.c: Executing [424242@from-internal:4] Set("PJSIP/109-00000002", "CDR(cdr_direction)=3") in new stack
[May 25 19:31:08] VERBOSE[69495][C-00000002] pbx.c: Executing [424242@from-internal:5] Set("PJSIP/109-00000002", "CDR(cdr_internal_from_extension)=109") in new stack
[May 25 19:31:08] VERBOSE[69495][C-00000002] pbx.c: Executing [424242@from-internal:6] Set("PJSIP/109-00000002", "CDR(cdr_internal_to_extension)=424242") in new stack
[May 25 19:31:08] VERBOSE[69495][C-00000002] pbx.c: Executing [424242@from-internal:7] Set("PJSIP/109-00000002", "CALLERID(name)=q4rtq244109") in new stack
[May 25 19:31:08] VERBOSE[69495][C-00000002] pbx.c: Executing [424242@from-internal:8] Queue("PJSIP/109-00000002", "linearQ,wxRn") in new stack
[May 25 19:31:08] WARNING[69495][C-00000002] res_musiconhold.c: Music on Hold class '0' not found in memory. Verify your configuration.
[May 25 19:31:08] VERBOSE[69495][C-00000002] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/109-00000002'
[May 25 19:31:08] ERROR[69391] res_pjsip.c: Endpoint '100': Could not create dialog to invalid URI '100'.  Is endpoint registered?
[May 25 19:31:08] ERROR[69391] chan_pjsip.c: Failed to create outgoing session to endpoint '100'
[May 25 19:31:08] VERBOSE[69495][C-00000002] app_queue.c: Called PJSIP/103
[May 25 19:31:08] VERBOSE[69495][C-00000002] app_queue.c: PJSIP/103-00000003 is ringing
[May 25 19:31:08] VERBOSE[69495][C-00000002] res_musiconhold.c: Stopped music on hold on PJSIP/109-00000002
[May 25 19:31:13] VERBOSE[69495][C-00000002] app_queue.c: Nobody picked up in 5000 ms
[May 25 19:31:13] WARNING[69495][C-00000002] res_musiconhold.c: Music on Hold class '0' not found in memory. Verify your configuration.
[May 25 19:31:13] VERBOSE[69495][C-00000002] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/109-00000002'
[May 25 19:31:18] VERBOSE[69495][C-00000002] app_queue.c: Called PJSIP/102
[May 25 19:31:18] VERBOSE[69495][C-00000002] app_queue.c: PJSIP/102-00000004 is ringing
[May 25 19:31:18] VERBOSE[69495][C-00000002] res_musiconhold.c: Stopped music on hold on PJSIP/109-00000002
[May 25 19:31:23] VERBOSE[69495][C-00000002] app_queue.c: Nobody picked up in 5000 ms
[May 25 19:31:23] WARNING[69495][C-00000002] res_musiconhold.c: Music on Hold class '0' not found in memory. Verify your configuration.
[May 25 19:31:23] VERBOSE[69495][C-00000002] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/109-00000002'
[May 25 19:31:28] ERROR[69391] res_pjsip.c: Endpoint '100': Could not create dialog to invalid URI '100'.  Is endpoint registered?
[May 25 19:31:28] ERROR[69391] chan_pjsip.c: Failed to create outgoing session to endpoint '100'
[May 25 19:31:28] VERBOSE[69495][C-00000002] app_queue.c: Called PJSIP/103
[May 25 19:31:28] VERBOSE[69495][C-00000002] app_queue.c: PJSIP/103-00000005 is ringing
[May 25 19:31:28] VERBOSE[69495][C-00000002] res_musiconhold.c: Stopped music on hold on PJSIP/109-00000002
[May 25 19:31:33] VERBOSE[69495][C-00000002] app_queue.c: Nobody picked up in 5000 ms
[May 25 19:31:33] WARNING[69495][C-00000002] res_musiconhold.c: Music on Hold class '0' not found in memory. Verify your configuration.
[May 25 19:31:33] VERBOSE[69495][C-00000002] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/109-00000002'
[May 25 19:31:38] VERBOSE[69495][C-00000002] app_queue.c: Called PJSIP/102
[May 25 19:31:38] VERBOSE[69495][C-00000002] app_queue.c: PJSIP/102-00000006 is ringing
[May 25 19:31:38] VERBOSE[69495][C-00000002] res_musiconhold.c: Stopped music on hold on PJSIP/109-00000002
[May 25 19:31:40] VERBOSE[69465] asterisk.c: Remote UNIX connection disconnected
[May 25 19:31:43] VERBOSE[69495][C-00000002] app_queue.c: Nobody picked up in 5000 ms
[May 25 19:31:43] WARNING[69495][C-00000002] res_musiconhold.c: Music on Hold class '0' not found in memory. Verify your configuration.
[May 25 19:31:43] VERBOSE[69495][C-00000002] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/109-00000002'
[May 25 19:31:43] VERBOSE[69495][C-00000002] app_queue.c: Exiting on time-out cycle
[May 25 19:31:43] VERBOSE[69495][C-00000002] res_musiconhold.c: Stopped music on hold on PJSIP/109-00000002
[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [424242@from-internal:9] Hangup("PJSIP/109-00000002", "") in new stack
[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Spawn extension (from-internal, 424242, 9) exited non-zero on 'PJSIP/109-00000002'
[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:1] NoOp("PJSIP/109-00000002", "some CDR stuff") in new stack
[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:2] Set("PJSIP/109-00000002", "CDR(cdr_internal_to_extension)=") in new stack
[May 25 19:31:43] WARNING[69376] func_cdr.c: CDR requires a value (CDR(variable)=value)
)[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:3] Set("PJSIP/109-00000002", "CDR(cdr_queue_member)=") in new stack
[May 25 19:31:43] WARNING[69376] func_cdr.c: CDR requires a value (CDR(variable)=value)
)[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:4] Set("PJSIP/109-00000002", "CDR(cdr_queue_member_calls)=") in new stack
[May 25 19:31:43] WARNING[69376] func_cdr.c: CDR requires a value (CDR(variable)=value)
)[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:5] Set("PJSIP/109-00000002", "CDR(cdr_queue_member_last_call)=") in new stack
[May 25 19:31:43] WARNING[69376] func_cdr.c: CDR requires a value (CDR(variable)=value)
)[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:6] Set("PJSIP/109-00000002", "CDR(cdr_queue_hold_time)=") in new stack
[May 25 19:31:43] WARNING[69376] func_cdr.c: CDR requires a value (CDR(variable)=value)
)[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:7] Set("PJSIP/109-00000002", "CDR(cdr_queue_original_pos)=") in new stack
[May 25 19:31:43] WARNING[69376] func_cdr.c: CDR requires a value (CDR(variable)=value)
)[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:8] Set("PJSIP/109-00000002", "CDR(cdr_queue_calls)=1") in new stack
[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:9] Set("PJSIP/109-00000002", "CDR(cdr_queue_avg_hold_time)=0") in new stack
[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:10] Set("PJSIP/109-00000002", "CDR(cdr_queue_completed)=0") in new stack
[May 25 19:31:43] VERBOSE[69495][C-00000002] pbx.c: Executing [h@from-internal:11] Set("PJSIP/109-00000002", "CDR(cdr_queue_abandoned)=1") in new stack
[May 25 19:31:56] VERBOSE[69368] asterisk.c: Remote UNIX connection
[May 25 19:32:01] DEBUG[69391] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[May 25 19:32:01] DEBUG[69391] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:01] DEBUG[69391] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[May 25 19:32:01] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Wrapper created
[May 25 19:32:01] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Set timer to 20000 msec
[May 25 19:32:01] DEBUG[69391] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to serverIP:5060
[May 25 19:32:01] DEBUG[69391] netsock2.c: Splitting 'serverIP:5060' into...
[May 25 19:32:01] DEBUG[69391] netsock2.c: ...host 'serverIP' and port '5060'.
[May 25 19:32:01] DEBUG[69391] netsock2.c: Splitting 'officeIP:1209' into...
[May 25 19:32:01] DEBUG[69391] netsock2.c: ...host 'officeIP' and port '1209'.
[May 25 19:32:01] DEBUG[69390] netsock2.c: Splitting 'officeIP:1209' into...
[May 25 19:32:01] DEBUG[69390] netsock2.c: ...host 'officeIP' and port '1209'.
[May 25 19:32:01] DEBUG[69390] netsock2.c: Splitting 'serverIP:5060' into...
[May 25 19:32:01] DEBUG[69390] netsock2.c: ...host 'serverIP' and port '5060'.
[May 25 19:32:01] DEBUG[69390] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 200/OPTIONS/cseq=41319 (rdata0x2b55308).  Using request transaction as basis.
[May 25 19:32:01] DEBUG[69390] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7f417c002bd8 for Response msg 200/OPTIONS/cseq=41319 (rdata0x2b55308).
[May 25 19:32:01] DEBUG[69390] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-00000010 on transaction tsx0x7f417c002bd8
[May 25 19:32:01] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: PJSIP tsx response received
[May 25 19:32:01] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Cancelling timer
[May 25 19:32:01] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Timer cancelled
[May 25 19:32:01] DEBUG[69391] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[May 25 19:32:01] DEBUG[69391] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:01] DEBUG[69391] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[May 25 19:32:01] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Callbacks executed
[May 25 19:32:01] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: wrapper destroyed
[May 25 19:32:01] DEBUG[69396] res_pjsip/pjsip_configuration.c: Contact 103/sip:103@officeIP:1209 status didn't change: Reachable, RTT: 41.491 msec
[May 25 19:32:03] DEBUG[69499] threadpool.c: Worker thread idle timeout reached. Dying.
[May 25 19:32:03] DEBUG[69364] threadpool.c: Destroying worker thread 29
[May 25 19:32:03] DEBUG[69365] threadpool.c: Worker thread idle timeout reached. Dying.
[May 25 19:32:03] DEBUG[69364] threadpool.c: Destroying worker thread 0
[May 25 19:32:03] DEBUG[69466] manager.c: Running action 'Ping'
[May 25 19:32:04] DEBUG[69391] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[May 25 19:32:04] DEBUG[69391] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:04] DEBUG[69391] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[May 25 19:32:04] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Wrapper created
[May 25 19:32:04] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Set timer to 20000 msec
[May 25 19:32:04] DEBUG[69391] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to serverIP:5060
[May 25 19:32:04] DEBUG[69391] netsock2.c: Splitting 'serverIP:5060' into...
[May 25 19:32:04] DEBUG[69391] netsock2.c: ...host 'serverIP' and port '5060'.
[May 25 19:32:04] DEBUG[69391] netsock2.c: Splitting 'officeIP:5060' into...
[May 25 19:32:04] DEBUG[69391] netsock2.c: ...host 'officeIP' and port '5060'.
[May 25 19:32:04] DEBUG[69390] netsock2.c: Splitting 'officeIP:5060' into...
[May 25 19:32:04] DEBUG[69390] netsock2.c: ...host 'officeIP' and port '5060'.
[May 25 19:32:04] DEBUG[69390] netsock2.c: Splitting 'serverIP:5060' into...
[May 25 19:32:04] DEBUG[69390] netsock2.c: ...host 'serverIP' and port '5060'.
[May 25 19:32:04] DEBUG[69390] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 200/OPTIONS/cseq=14485 (rdata0x2b55308).  Using request transaction as basis.
[May 25 19:32:04] DEBUG[69390] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7f417c008c28 for Response msg 200/OPTIONS/cseq=14485 (rdata0x2b55308).
[May 25 19:32:04] DEBUG[69390] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-00000011 on transaction tsx0x7f417c008c28
[May 25 19:32:04] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: PJSIP tsx response received
[May 25 19:32:04] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Cancelling timer
[May 25 19:32:04] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Timer cancelled
[May 25 19:32:04] DEBUG[69391] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[May 25 19:32:04] DEBUG[69391] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:04] DEBUG[69391] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[May 25 19:32:04] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: Callbacks executed
[May 25 19:32:04] DEBUG[69391] res_pjsip.c: 0x7f418803ab00: wrapper destroyed
[May 25 19:32:04] DEBUG[69396] res_pjsip/pjsip_configuration.c: Contact 109/sip:109@officeIP:5060 status didn't change: Reachable, RTT: 29.815 msec
[May 25 19:32:05] DEBUG[69390] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[May 25 19:32:05] DEBUG[69390] res_pjsip_session.c: inv_session 0x7f4188027ea8 has no ast session
[May 25 19:32:05] DEBUG[69390] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[May 25 19:32:05] DEBUG[69390] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f417c02e558
[May 25 19:32:05] DEBUG[69390] res_pjsip_session.c: The current transaction state is Terminated
[May 25 19:32:05] DEBUG[69390] res_pjsip_session.c: The transaction state change event is TIMER
[May 25 19:32:05] DEBUG[69390] res_pjsip_session.c: The current inv state is DISCONNCTD
[May 25 19:32:05] DEBUG[69391] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[May 25 19:32:05] DEBUG[69391] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:05] DEBUG[69391] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[May 25 19:32:05] DEBUG[69391] res_pjsip.c: 0x7f41880133d0: Wrapper created
[May 25 19:32:05] DEBUG[69391] res_pjsip.c: 0x7f41880133d0: Set timer to 20000 msec
[May 25 19:32:05] DEBUG[69391] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to serverIP:5060
[May 25 19:32:05] DEBUG[69391] netsock2.c: Splitting 'serverIP:5060' into...
[May 25 19:32:05] DEBUG[69391] netsock2.c: ...host 'serverIP' and port '5060'.
[May 25 19:32:05] DEBUG[69391] netsock2.c: Splitting 'officeIP:1209' into...
[May 25 19:32:05] DEBUG[69391] netsock2.c: ...host 'officeIP' and port '1209'.
[May 25 19:32:05] DEBUG[69390] netsock2.c: Splitting 'officeIP:1209' into...
[May 25 19:32:05] DEBUG[69390] netsock2.c: ...host 'officeIP' and port '1209'.
[May 25 19:32:05] DEBUG[69390] netsock2.c: Splitting 'serverIP:5060' into...
[May 25 19:32:05] DEBUG[69390] netsock2.c: ...host 'serverIP' and port '5060'.
[May 25 19:32:05] DEBUG[69390] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 200/OPTIONS/cseq=41664 (rdata0x2b55308).  Using request transaction as basis.
[May 25 19:32:05] DEBUG[69390] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7f417c02e558 for Response msg 200/OPTIONS/cseq=41664 (rdata0x2b55308).
[May 25 19:32:05] DEBUG[69390] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-00000012 on transaction tsx0x7f417c02e558
[May 25 19:32:05] DEBUG[69391] res_pjsip.c: 0x7f41880133d0: PJSIP tsx response received
[May 25 19:32:05] DEBUG[69391] res_pjsip.c: 0x7f41880133d0: Cancelling timer
[May 25 19:32:05] DEBUG[69391] res_pjsip.c: 0x7f41880133d0: Timer cancelled
[May 25 19:32:05] DEBUG[69391] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[May 25 19:32:05] DEBUG[69391] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:05] DEBUG[69391] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[May 25 19:32:05] DEBUG[69391] res_pjsip.c: 0x7f41880133d0: Callbacks executed
[May 25 19:32:05] DEBUG[69391] res_pjsip.c: 0x7f41880133d0: wrapper destroyed
[May 25 19:32:05] DEBUG[69396] res_pjsip/pjsip_configuration.c: Contact 102/sip:102@officeIP:1209 status didn't change: Reachable, RTT: 31.094 msec
[May 25 19:32:05] DEBUG[69466] manager.c: Running action 'ExtensionStateList'
[May 25 19:32:05] DEBUG[69466] manager.c: Running action 'PJSIPShowRegistrationInboundContactStatuses'
[May 25 19:32:05] DEBUG[69466] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract double from [20.000000] in [-inf, inf] gives [20.000000](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract uint from [15] in [0, 86400] gives [15](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract double from [20.000000] in [-inf, inf] gives [20.000000](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract uint from [15] in [0, 86400] gives [15](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract double from [20.000000] in [-inf, inf] gives [20.000000](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract uint from [15] in [0, 86400] gives [15](0)
[May 25 19:32:05] DEBUG[69466] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0)
[May 25 19:32:06] DEBUG[69467] manager.c: Running action 'Ping'
[May 25 19:32:09] DEBUG[69429] res_pjsip_registrar_expire.c: Woke up at 1495740729  Interval: 30
[May 25 19:32:09] DEBUG[69429] res_pjsip_registrar_expire.c: Expiring 0 contacts
[May 25 19:32:15] DEBUG[69390] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[May 25 19:32:15] DEBUG[69390] res_pjsip_session.c: inv_session 0x7f4188018c68 has no ast session
[May 25 19:32:15] DEBUG[69390] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[May 25 19:32:15] DEBUG[69390] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f4180003b88
[May 25 19:32:15] DEBUG[69390] res_pjsip_session.c: The current transaction state is Terminated
[May 25 19:32:15] DEBUG[69390] res_pjsip_session.c: The transaction state change event is TIMER
[May 25 19:32:15] DEBUG[69390] res_pjsip_session.c: The current inv state is DISCONNCTD
[May 25 19:32:16] DEBUG[69391] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[May 25 19:32:16] DEBUG[69391] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:16] DEBUG[69391] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[May 25 19:32:16] DEBUG[69391] res_pjsip.c: 0x7f4188018bb0: Wrapper created
[May 25 19:32:16] DEBUG[69391] res_pjsip.c: 0x7f4188018bb0: Set timer to 20000 msec
[May 25 19:32:16] DEBUG[69391] res_pjsip/pjsip_message_ip_updater.c: Re-wrote Contact URI host/port to serverIP:5060
[May 25 19:32:16] DEBUG[69391] netsock2.c: Splitting 'serverIP:5060' into...
[May 25 19:32:16] DEBUG[69391] netsock2.c: ...host 'serverIP' and port '5060'.
[May 25 19:32:16] DEBUG[69391] netsock2.c: Splitting 'officeIP:1209' into...
[May 25 19:32:16] DEBUG[69391] netsock2.c: ...host 'officeIP' and port '1209'.
[May 25 19:32:16] DEBUG[69390] netsock2.c: Splitting 'officeIP:1209' into...
[May 25 19:32:16] DEBUG[69390] netsock2.c: ...host 'officeIP' and port '1209'.
[May 25 19:32:16] DEBUG[69390] netsock2.c: Splitting 'serverIP:5060' into...
[May 25 19:32:16] DEBUG[69390] netsock2.c: ...host 'serverIP' and port '5060'.
[May 25 19:32:16] DEBUG[69390] res_pjsip/pjsip_distributor.c: No dialog serializer for Response msg 200/OPTIONS/cseq=51093 (rdata0x2b55308).  Using request transaction as basis.
[May 25 19:32:16] DEBUG[69390] res_pjsip/pjsip_distributor.c: Found transaction tsx0x7f4180003b88 for Response msg 200/OPTIONS/cseq=51093 (rdata0x2b55308).
[May 25 19:32:16] DEBUG[69390] res_pjsip/pjsip_distributor.c: Found serializer pjsip/default-00000013 on transaction tsx0x7f4180003b88
[May 25 19:32:16] DEBUG[69391] res_pjsip.c: 0x7f4188018bb0: PJSIP tsx response received
[May 25 19:32:16] DEBUG[69391] res_pjsip.c: 0x7f4188018bb0: Cancelling timer
[May 25 19:32:16] DEBUG[69391] res_pjsip.c: 0x7f4188018bb0: Timer cancelled
[May 25 19:32:16] DEBUG[69391] config.c: extract uint from [3] in [0, 4294967295] gives [3](0)
[May 25 19:32:16] DEBUG[69391] config.c: extract uint from [0] in [0, 4294967295] gives [0](0)
[May 25 19:32:16] DEBUG[69391] config.c: extract uint from [2] in [0, 4294967295] gives [2](0)
[May 25 19:32:16] DEBUG[69391] res_pjsip.c: 0x7f4188018bb0: Callbacks executed
[May 25 19:32:16] DEBUG[69391] res_pjsip.c: 0x7f4188018bb0: wrapper destroyed
[May 25 19:32:16] DEBUG[69396] res_pjsip/pjsip_configuration.c: Contact 103/sip:103@officeIP:1209 status didn't change: Reachable, RTT: 37.928 msec
[May 25 19:32:16] DEBUG[69466] manager.c: Running action 'Ping'