[sr-dev] Unable to make SIP Calls (403 Forbidden - Domain not served)

Prasannakumar Merugu mprasanna469 at gmail.com
Thu May 25 12:48:11 CEST 2017


Hello All,

We have Installed Kamailio in Debain 8.
All p,s,i and hss servers are in one PC.

We are able to register the users(Alice and Bob).

When initiate call from Alice , INVITE is passing through
 Alice -> p-cscf -> i-cscs -> s-cscf -> i-cscf -> s-cscf

when it is reaching again s-cscf server, we are getting error .(403
Forbidden  - Domain not served)

We are attaching all logs and wireshark logs.

Kindly let us know, where and why it is failing.

regards,
Prasannakumar.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20170525/e0f0fc57/attachment-0001.html>
-------------- next part --------------
koffee at debian-km:~$ su
Password: 
su: Authentication failure
koffee at debian-km:~$ su
Password: 
root at debian-km:/home/koffee# cd /root/
root at debian-km:~# ./hss.sh 
Building Classpath
Classpath is lib/xml-apis.jar:lib/xercesImpl.jar:lib/xerces-2.4.0.jar:lib/xalan-2.4.0.jar:lib/tomcat-util.jar:lib/tomcat-http.jar:lib/tomcat-coyote.jar:lib/struts.jar:lib/servlets-default.jar:lib/servlet-api.jar:lib/naming-resources.jar:lib/naming-factory.jar:lib/mysql-connector-java-3.1.12-bin.jar:lib/mx4j-3.0.1.jar:lib/log4j.jar:lib/junit.jar:lib/junitee.jar:lib/jta.jar:lib/jsp-api.jar:lib/jmx.jar:lib/jdp.jar:lib/jasper-runtime.jar:lib/jasper-compiler-jdt.jar:lib/jasper-compiler.jar:lib/hibernate3.jar:lib/FHoSS.jar:lib/ehcache-1.1.jar:lib/dom4j-1.6.1.jar:lib/commons-validator.jar:lib/commons-modeler.jar:lib/commons-logging.jar:lib/commons-logging-1.0.4.jar:lib/commons-lang.jar:lib/commons-fileupload.jar:lib/commons-el.jar:lib/commons-digester.jar:lib/commons-collections-3.1.jar:lib/commons-beanutils.jar:lib/cglib-2.1.3.jar:lib/catalina-optional.jar:lib/catalina.jar:lib/c3p0-0.9.1.jar:lib/base64.jar:lib/asm.jar:lib/asm-attrs.jar:lib/antlr-2.7.6.jar::log4j.properties:..
[main] INFO  de.fhg.fokus.hss.main.TomcatServer  - Tomcat-Server is started.
[main] INFO  org.apache.catalina.startup.Embedded  - Starting tomcat server
[main] INFO  org.apache.catalina.core.StandardEngine  - Starting Servlet Engine: Apache Tomcat/5.5.9
[main] INFO  org.apache.coyote.http11.Http11Protocol  - Initializing Coyote HTTP/1.1 on http-192.168.99.140-8080
[main] INFO  org.apache.coyote.http11.Http11Protocol  - Starting Coyote HTTP/1.1 on http-192.168.99.140-8080
[main] WARN  org.apache.catalina.connector.MapperListener  - Unknown default host: 192.168.99.140
[main] INFO  org.apache.catalina.core.StandardHost  - XML validation disabled
[main] INFO  de.fhg.fokus.hss.web.servlet.ResponseFilter  - Response Filter Initialisation!
log4j:WARN No appenders could be found for logger (org.apache.catalina.loader.WebappClassLoader).
log4j:WARN Please initialize the log4j system properly.
[main] INFO  org.apache.struts.tiles.TilesPlugin  - Tiles definition factory loaded for module ''.
[main] INFO  org.apache.struts.validator.ValidatorPlugIn  - Loading validation rules file from '/WEB-INF/validator-rules.xml'
[main] INFO  org.apache.struts.validator.ValidatorPlugIn  - Loading validation rules file from '/WEB-INF/validation.xml'
[main] INFO  de.fhg.fokus.hss.main.TomcatServer  - WebConsole of FHoSS was started !
[main] INFO  org.hibernate.cfg.Environment  - Hibernate 3.2.1
[main] INFO  org.hibernate.cfg.Environment  - loaded properties from resource hibernate.properties: {hibernate.c3p0.timeout=3600, hibernate.connection.driver_class=com.mysql.jdbc.Driver, hibernate.connection.isolation=1, hibernate.c3p0.max_statements=0, hibernate.c3p0.max_size=30, hibernate.dialect=org.hibernate.dialect.MySQLDialect, hibernate.c3p0.idle_test_period=1200, hibernate.c3p0.min_size=1, hibernate.connection.username=hss, hibernate.c3p0.acquire_increment=1, hibernate.connection.url=jdbc:mysql://192.168.99.140:3306/hss_db, hibernate.bytecode.use_reflection_optimizer=false, hibernate.connection.password=****}
[main] INFO  org.hibernate.cfg.Environment  - Bytecode provider name : cglib
[main] INFO  org.hibernate.cfg.Environment  - using JDK 1.4 java.sql.Timestamp handling
[main] INFO  org.hibernate.cfg.Configuration  - configuring from resource: /hibernate.cfg.xml
[main] INFO  org.hibernate.cfg.Configuration  - Configuration resource: /hibernate.cfg.xml
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/ApplicationServer.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.ApplicationServer -> application_server
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/CapabilitiesSet.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.CapabilitiesSet -> capabilities_set
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/Capability.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.Capability -> capability
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/ChargingInfo.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.ChargingInfo -> charging_info
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/DSAI_IMPU.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.DSAI_IMPU -> dsai_impu
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/DSAI_IFC.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.DSAI_IFC -> dsai_ifc
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/DSAI.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.DSAI -> dsai
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/IFC.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.IFC -> ifc
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/IMPI_IMPU.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.IMPI_IMPU -> impi_impu
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/IMPI.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.IMPI -> impi
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/IMPU.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.IMPU -> impu
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/IMPU_VisitedNetwork.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.IMPU_VisitedNetwork -> impu_visited_network
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/IMSU.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.IMSU -> imsu
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/Preferred_SCSCF_Set.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.Preferred_SCSCF_Set -> preferred_scscf_set
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/CxEvents.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.CxEvents -> cx_events
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/Shared_IFC_Set.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.Shared_IFC_Set -> shared_ifc_set
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/ShNotification.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.ShNotification -> sh_notification
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/ShSubscription.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.ShSubscription -> sh_subscription
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/SP_IFC.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.SP_IFC -> sp_ifc
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/SP_Shared_IFC_Set.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.SP_Shared_IFC_Set -> sp_shared_ifc_set
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/SP.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.SP -> sp
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/SPT.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.SPT -> spt
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/TP.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.TP -> tp
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/VisitedNetwork.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.VisitedNetwork -> visited_network
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/RepositoryData.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.RepositoryData -> repository_data
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/AliasesRepositoryData.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.AliasesRepositoryData -> aliases_repository_data
[main] INFO  org.hibernate.cfg.Configuration  - Reading mappings from resource : mappings/Zh_USS.hbm.xml
[main] INFO  org.hibernate.cfg.HbmBinder  - Mapping class: de.fhg.fokus.hss.db.model.Zh_USS -> zh_uss
[main] INFO  org.hibernate.cfg.Configuration  - Configured SessionFactory: foo
[main] INFO  org.hibernate.connection.C3P0ConnectionProvider  - C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://192.168.99.140:3306/hss_db
[main] INFO  org.hibernate.connection.C3P0ConnectionProvider  - Connection properties: {user=hss, password=****, autocommit=false}
[main] INFO  org.hibernate.connection.C3P0ConnectionProvider  - autocommit mode: false
[main] INFO  com.mchange.v2.log.MLog  - MLog clients using log4j logging.
[main] INFO  com.mchange.v2.c3p0.C3P0Registry  - Initializing c3p0-0.9.1 [built 16-January-2007 14:46:42; debug? true; trace: 10]
[main] INFO  org.hibernate.connection.C3P0ConnectionProvider  - JDBC isolation level: READ_UNCOMMITTED
[main] INFO  com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource  - Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource at 14f2d5e6 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource at 5ecb3caf [ acquireIncrement -> 1, acquireRetryAttempts -> 60, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> z8kfsx9ohh4e8p1qhvk36|1716c3d, idleConnectionTestPeriod -> 1200, initialPoolSize -> 1, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 3600, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 30, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 1, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource at 6640022c [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> z8kfsx9ohh4e8p1qhvk36|11bfb7e, jdbcUrl -> jdbc:mysql://192.168.99.140:3306/hss_db, properties -> {user=******, password=******, autocommit=false} ], preferredTestQuery -> null, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> z8kfsx9ohh4e8p1qhvk36|1b8ebe3, numHelperThreads -> 3 ]
[main] INFO  org.hibernate.cfg.SettingsFactory  - RDBMS: MySQL, version: 5.5.55-0+deb8u1
[main] INFO  org.hibernate.cfg.SettingsFactory  - JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.1.12 ( $Date: 2005-11-17 15:53:48 +0100 (Thu, 17 Nov 2005) $, $Revision$ )
[main] INFO  org.hibernate.dialect.Dialect  - Using dialect: org.hibernate.dialect.MySQLDialect
[main] INFO  org.hibernate.transaction.TransactionFactoryFactory  - Using default transaction strategy (direct JDBC transactions)
[main] INFO  org.hibernate.transaction.TransactionManagerLookupFactory  - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
[main] INFO  org.hibernate.cfg.SettingsFactory  - Automatic flush during beforeCompletion(): disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Automatic session close at end of transaction: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - JDBC batch size: 15
[main] INFO  org.hibernate.cfg.SettingsFactory  - JDBC batch updates for versioned data: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Scrollable result sets: enabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - JDBC3 getGeneratedKeys(): enabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Connection release mode: auto
[main] INFO  org.hibernate.cfg.SettingsFactory  - Maximum outer join fetch depth: 2
[main] INFO  org.hibernate.cfg.SettingsFactory  - Default batch fetch size: 1
[main] INFO  org.hibernate.cfg.SettingsFactory  - Generate SQL with comments: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Order SQL updates by primary key: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
[main] INFO  org.hibernate.hql.ast.ASTQueryTranslatorFactory  - Using ASTQueryTranslatorFactory
[main] INFO  org.hibernate.cfg.SettingsFactory  - Query language substitutions: {}
[main] INFO  org.hibernate.cfg.SettingsFactory  - JPA-QL strict compliance: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Second-level cache: enabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Query cache: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Cache provider: org.hibernate.cache.NoCacheProvider
[main] INFO  org.hibernate.cfg.SettingsFactory  - Optimize cache for minimal puts: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Structured second-level cache entries: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Statistics: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Deleted entity synthetic identifier rollback: disabled
[main] INFO  org.hibernate.cfg.SettingsFactory  - Default entity-mode: pojo
[main] INFO  org.hibernate.impl.SessionFactoryImpl  - building session factory
[main] INFO  org.hibernate.impl.SessionFactoryObjectFactory  - Factory name: foo
[main] INFO  org.hibernate.util.NamingHelper  - JNDI InitialContext properties:{}
[main] INFO  org.hibernate.impl.SessionFactoryObjectFactory  - Bound factory to JNDI name: foo
[main] WARN  org.hibernate.impl.SessionFactoryObjectFactory  - InitialContext did not implement EventContext
[main] INFO  de.fhg.fokus.diameter.DiameterPeer.DiameterPeer  - Bean style constructor called, don't forget to configure!
[main] INFO  de.fhg.fokus.diameter.DiameterPeer.DiameterPeer  - FQDN: hss.koffee-ims.in
[main] INFO  de.fhg.fokus.diameter.DiameterPeer.DiameterPeer  - Realm: koffee-ims.in
[main] INFO  de.fhg.fokus.diameter.DiameterPeer.DiameterPeer  - Vendor_ID : 10415
[main] INFO  de.fhg.fokus.diameter.DiameterPeer.DiameterPeer  - Product Name: JavaDiameterPeer
[main] INFO  de.fhg.fokus.diameter.DiameterPeer.DiameterPeer  - AcceptUnknwonPeers: true
[main] INFO  de.fhg.fokus.diameter.DiameterPeer.DiameterPeer  - DropUnknownOnDisconnect: true
[main] INFO  de.fhg.fokus.hss.main.HSSContainer  - 
Type "exit" to stop FHoSS!
[Thread-24] ERROR de.fhg.fokus.diameter.DiameterPeer.peer.StateMachine  - StateMachine: Peer icscf.koffee-ims.in:3869 not responding to connection attempt 
[Thread-24] ERROR de.fhg.fokus.diameter.DiameterPeer.peer.StateMachine  - StateMachine: Peer scscf.koffee-ims.in:3870 not responding to connection attempt 
[Thread-24] ERROR de.fhg.fokus.diameter.DiameterPeer.peer.StateMachine  - StateMachine: Peer icscf.koffee-ims.in:3869 not responding to connection attempt 
[Thread-24] ERROR de.fhg.fokus.diameter.DiameterPeer.peer.StateMachine  - StateMachine: Peer scscf.koffee-ims.in:3870 not responding to connection attempt 
[Thread-16] INFO  de.fhg.fokus.hss.cx.op.SAR  - 

The UserData XML document which is sent to the S-CSCF:
<?xml version="1.0" encoding="UTF-8"?><IMSSubscription><PrivateID>alice at koffee-ims.in</PrivateID><ServiceProfile><PublicIdentity><Identity>sip:alice at koffee-ims.in</Identity><Extension><IdentityType>0</IdentityType></Extension></PublicIdentity><InitialFilterCriteria><Priority>0</Priority><TriggerPoint><ConditionTypeCNF>0</ConditionTypeCNF><SPT><ConditionNegated>0</ConditionNegated><Group>0</Group><Method>PUBLISH</Method><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>0</Group><SIPHeader><Header>Event</Header><Content>.*presence.*</Content></SIPHeader><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>0</Group><SessionCase>0</SessionCase><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>1</Group><Method>PUBLISH</Method><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>1</Group><SIPHeader><Header>Event</Header><Content>.*presence.*</Content></SIPHeader><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>1</Group><SessionCase>3</SessionCase><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>2</Group><Method>SUBSCRIBE</Method><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>2</Group><SIPHeader><Header>Event</Header><Content>.*presence.*</Content></SIPHeader><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>2</Group><SessionCase>1</SessionCase><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>3</Group><Method>SUBSCRIBE</Method><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>3</Group><SIPHeader><Header>Event</Header><Content>.*presence.*</Content></SIPHeader><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>3</Group><SessionCase>2</SessionCase><Extension></Extension></SPT></TriggerPoint><ApplicationServer><ServerName>sip:192.168.99.140:5065</ServerName><DefaultHandling>0</DefaultHandling></ApplicationServer></InitialFilterCriteria></ServiceProfile></IMSSubscription>
[Thread-16] INFO  de.fhg.fokus.hss.cx.op.SAR  - 
User with Public Identity: sip:alice at koffee-ims.in and all its coresponding implicit-set identities are Registered!


-------------- next part --------------
A non-text attachment was scrubbed...
Name: calling-party.pcapng
Type: application/x-pcapng
Size: 1345632 bytes
Desc: not available
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20170525/e0f0fc57/attachment-0002.bin>
-------------- next part --------------
koffee at debian-km:~$ su
Password: 
root at debian-km:/home/koffee# kamailio -f /usr/local/etc/icscf/kamailio.cfg 
loading modules under config path: /usr/local/src/kamailio-5.0/kamailio/src/modules/
 0(3041) INFO: <core> [core/sctp_core.c:75]: sctp_core_check_support(): SCTP API not enabled - if you want to use it, load sctp module
Listening on 
             udp: 192.168.99.140 [192.168.99.140]:4060
             tcp: 192.168.99.140 [192.168.99.140]:4060
Aliases: 
             *: icscf.koffee-ims.in:*

 0(3041) INFO: <core> [core/tcp_main.c:4665]: init_tcp(): using epoll_lt as the io watch method (auto detected)
 0(3043) INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded
 0(3043) INFO: rr [rr_mod.c:175]: mod_init(): outbound module not available
 0(3043) INFO: pike [pike.c:99]: pike_init(): PIKE - initializing
 0(3043) INFO: pike [ip_tree.c:81]: init_lock_set(): probing 256 set size
 0(3043) INFO: jsonrpcs [jsonrpcs_sock.c:197]: jsonrpc_dgram_mod_init(): the socket /var/run/kamailio/kamailio_rpc.sock already exists, trying to delete it...
 0(3043) ERROR: ims_icscf [db.c:273]: ims_icscf_db_get_scscf(): ERR:ims_icscf_db_get_scscf:  no S-CSCFs found
 0(3043) INFO: <core> [core/udp_server.c:153]: probe_max_receive_buffer(): SO_RCVBUF is initially 163840
 0(3043) INFO: <core> [core/udp_server.c:203]: probe_max_receive_buffer(): SO_RCVBUF is finally 327680
68(3113) INFO: ctl [io_listener.c:214]: io_listen_loop(): io_listen_loop:  using epoll_lt io watch method (config)
 0(3043) INFO: cdp [cdp_mod.c:242]: cdp_child_init(): CDiameterPeer child starting ...
70(3115) INFO: jsonrpcs [jsonrpcs_sock.c:429]: jsonrpc_dgram_process(): a new child 0/3115
71(3116) INFO: cdp [worker.c:332]: worker_process(): [0] Worker process started...
72(3117) INFO: cdp [worker.c:332]: worker_process(): [1] Worker process started...
73(3118) INFO: cdp [worker.c:332]: worker_process(): [2] Worker process started...
74(3119) INFO: cdp [worker.c:332]: worker_process(): [3] Worker process started...
75(3120) INFO: cdp [worker.c:332]: worker_process(): [4] Worker process started...
76(3121) INFO: cdp [worker.c:332]: worker_process(): [5] Worker process started...
77(3122) INFO: cdp [worker.c:332]: worker_process(): [6] Worker process started...
78(3123) INFO: cdp [worker.c:332]: worker_process(): [7] Worker process started...
79(3124) INFO: cdp [worker.c:332]: worker_process(): [8] Worker process started...
80(3125) INFO: cdp [worker.c:332]: worker_process(): [9] Worker process started...
81(3126) INFO: cdp [worker.c:332]: worker_process(): [10] Worker process started...
82(3127) INFO: cdp [worker.c:332]: worker_process(): [11] Worker process started...
83(3128) INFO: cdp [worker.c:332]: worker_process(): [12] Worker process started...
84(3129) INFO: cdp [worker.c:332]: worker_process(): [13] Worker process started...
85(3130) INFO: cdp [worker.c:332]: worker_process(): [14] Worker process started...
86(3131) INFO: cdp [worker.c:332]: worker_process(): [15] Worker process started...
87(3132) INFO: cdp [receiver.c:450]: receiver_process(): receiver_process(): [] Receiver process doing init on new process...
87(3132) INFO: cdp [receiver.c:455]: receiver_process(): receiver_process(): [] Receiver process starting up...
88(3133) INFO: cdp [receiver.c:450]: receiver_process(): receiver_process(): [hss.koffee-ims.in] Receiver process doing init on new process...
88(3133) INFO: cdp [receiver.c:184]: add_serviced_peer(): add_serviced_peer(): Adding serviced_peer_t to receiver for peer [hss.koffee-ims.in]
88(3133) INFO: cdp [receiver.c:455]: receiver_process(): receiver_process(): [hss.koffee-ims.in] Receiver process starting up...
89(3134) INFO: cdp [acceptor.c:81]: acceptor_process(): Acceptor process starting up...
89(3134) WARNING: cdp [tcp_accept.c:121]: create_socket(): create_socket(): Trying to open/bind/listen on 192.168.99.140 port 3869
 0(3043) INFO: cdp [cdp_mod.c:244]: cdp_child_init(): ... CDiameterPeer child started
89(3134) WARNING: cdp [tcp_accept.c:146]: create_socket(): create_socket(): Successful socket open/bind/listen on 192.168.99.140 port 3869
89(3134) INFO: cdp [acceptor.c:95]: acceptor_process(): Acceptor opened sockets. Entering accept loop ...
90(3135) INFO: cdp [timer.c:205]: timer_process(): Timer process starting up...
root at debian-km:/home/koffee# 90(3135) INFO: cdp [peerstatemachine.c:525]: I_Snd_Conn_Req(): I_Snd_Conn_Req(): Peer hss.koffee-ims.in 
90(3135) INFO: cdp [receiver.c:869]: peer_connect(): peer_connect(): Trying to connect to 192.168.99.140 port 3868
90(3135) INFO: cdp [receiver.c:937]: peer_connect(): peer_connect(): Peer hss.koffee-ims.in:3868 connected
 1(3046) INFO: ims_icscf [cxdx_uar.c:71]: create_uaa_return_code(): created AVP successfully : [uaa_return_code]
71(3116) INFO: ims_icscf [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp
71(3116) INFO: ims_icscf [cxdx_uar.c:71]: create_uaa_return_code(): created AVP successfully : [uaa_return_code]
12(3057) INFO: ims_icscf [cxdx_uar.c:71]: create_uaa_return_code(): created AVP successfully : [uaa_return_code]
72(3117) INFO: ims_icscf [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_result_code: Failed finding avp
72(3117) INFO: ims_icscf [cxdx_uar.c:71]: create_uaa_return_code(): created AVP successfully : [uaa_return_code]
14(3059) ERROR: <script>: $ru => sip:alice at koffee-ims.in
14(3059) INFO: ims_icscf [cxdx_lir.c:69]: create_lia_return_code(): created AVP successfully : [lia_return_code]
73(3118) INFO: ims_icscf [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp
73(3118) INFO: ims_icscf [cxdx_lir.c:69]: create_lia_return_code(): created AVP successfully : [lia_return_code]
15(3060) ERROR: <script>: $ru => sip:bob at koffee-ims.in
16(3061) ERROR: <script>: $ru => sip:alice at koffee-ims.in
15(3060) INFO: ims_icscf [cxdx_lir.c:69]: create_lia_return_code(): created AVP successfully : [lia_return_code]
16(3061) INFO: ims_icscf [cxdx_lir.c:69]: create_lia_return_code(): created AVP successfully : [lia_return_code]
74(3119) INFO: ims_icscf [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp
74(3119) INFO: ims_icscf [cxdx_lir.c:69]: create_lia_return_code(): created AVP successfully : [lia_return_code]
75(3120) INFO: ims_icscf [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp
75(3120) INFO: ims_icscf [cxdx_lir.c:69]: create_lia_return_code(): created AVP successfully : [lia_return_code]
20(3065) ERROR: <script>: $ru => sip:bob at koffee-ims.in
20(3065) INFO: ims_icscf [cxdx_lir.c:69]: create_lia_return_code(): created AVP successfully : [lia_return_code]
76(3121) INFO: ims_icscf [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp
76(3121) INFO: ims_icscf [cxdx_lir.c:69]: create_lia_return_code(): created AVP successfully : [lia_return_code]
23(3068) WARNING: tm [t_lookup.c:1465]: t_unref(): script writer didn't release transaction


-------------- next part --------------
A non-text attachment was scrubbed...
Name: kamailio-setup-25May.pcapng
Type: application/x-pcapng
Size: 139972 bytes
Desc: not available
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20170525/e0f0fc57/attachment-0003.bin>
-------------- next part --------------
koffee at debian-km:~$ su
Password: 
root at debian-km:/home/koffee# kamailio -f /usr/local/etc/pcscf/kamailio.cfg 
loading modules under config path: /usr/local/src/kamailio-5.0/kamailio/src/modules/
 0(2947) INFO: pv [pv_shv.c:60]: shvar_init_locks(): locks array size 16
 0(2947) INFO: <core> [core/sctp_core.c:75]: sctp_core_check_support(): SCTP API not enabled - if you want to use it, load sctp module
Listening on 
             udp: 192.168.99.140 [192.168.99.140]:5060
Aliases: 
             *: pcscf.koffee-ims.in:*

 0(2949) INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded
 0(2949) INFO: rr [rr_mod.c:175]: mod_init(): outbound module not available
 0(2949) INFO: auth [auth_mod.c:347]: mod_init(): qop set, but nonce-count (nc_enabled) support disabled
 0(2949) INFO: path [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded
 0(2949) INFO: path [path_mod.c:147]: mod_init(): outbound module not available
 0(2949) INFO: ims_usrloc_pcscf [hslot.c:62]: ul_init_locks(): locks array size 512
 0(2949) INFO: pua [pua.c:412]: db_restore(): the query returned no result
 0(2949) ERROR: rtpengine [rtpengine.c:2361]: select_rtpp_set():  script error-invalid id_set to be selected
 0(2949) ERROR: rtpengine [rtpengine.c:2361]: select_rtpp_set():  script error-invalid id_set to be selected
 0(2949) NOTICE: rtpengine [rtpengine.c:1445]: mod_init(): Default rtpp set 0 NOT found
 0(2949) WARNING: tm [tm.c:515]: fixup_routes(): t_on_failure("NATMANAGE"): empty/non existing route
 0(2949) INFO: <core> [core/udp_server.c:153]: probe_max_receive_buffer(): SO_RCVBUF is initially 163840
 0(2949) INFO: <core> [core/udp_server.c:203]: probe_max_receive_buffer(): SO_RCVBUF is finally 327680
 0(2949) ERROR: <script>: event_route[htable:mod-init] {
 2(2953) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
 3(2954) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
 4(2956) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
 9(2968) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
 8(2967) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
12(2975) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
22(3000) INFO: jsonrpcs [jsonrpcs_sock.c:429]: jsonrpc_dgram_process(): a new child 0/3000
 5(2958) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
16(2983) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
 6(2961) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
13(2977) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
 1(2952) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
17(2986) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
23(3018) WARNING: ims_usrloc_pcscf [usrloc_db.c:61]: connect_db(): DB connection already open... continuing
10(2972) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
24(3019) WARNING: ims_usrloc_pcscf [usrloc_db.c:61]: connect_db(): DB connection already open... continuing
20(2993) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
 7(2965) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
14(2979) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
root at debian-km:/home/koffee# 19(2991) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
18(2989) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
15(2982) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
20(2993) INFO: ctl [io_listener.c:210]: io_listen_loop(): io_listen_loop: using epoll_lt as the io watch method (auto detected)
11(2974) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
24(3019) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
23(3018) INFO: rtpengine [rtpengine.c:2209]: rtpp_test(): rtp proxy <udp:127.0.0.1:2223> found, support for it enabled
24(3019) ERROR: <script>: Preloading NAT-PING. Rows: 44
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:49919;transport=udp via sip:192.168.99.145:49919...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:59023;transport=udp via sip:192.168.99.145:59023...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56624;transport=udp via sip:192.168.99.145:56624...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:49915;transport=udp via sip:192.168.99.21:49915...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:59567;transport=udp via sip:192.168.99.21:59567...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:61527;transport=udp via sip:192.168.99.145:61527...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56841;transport=udp via sip:192.168.99.145:56841...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:50394;transport=udp via sip:192.168.99.21:50394...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:65370;transport=udp via sip:192.168.99.21:65370...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:49919;transport=udp via sip:192.168.99.145:49919...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:59023;transport=udp via sip:192.168.99.145:59023...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56624;transport=udp via sip:192.168.99.145:56624...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:49915;transport=udp via sip:192.168.99.21:49915...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:59567;transport=udp via sip:192.168.99.21:59567...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:61527;transport=udp via sip:192.168.99.145:61527...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56841;transport=udp via sip:192.168.99.145:56841...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:50394;transport=udp via sip:192.168.99.21:50394...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:65370;transport=udp via sip:192.168.99.21:65370...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:49919;transport=udp via sip:192.168.99.145:49919...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:59023;transport=udp via sip:192.168.99.145:59023...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56624;transport=udp via sip:192.168.99.145:56624...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:49915;transport=udp via sip:192.168.99.21:49915...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:59567;transport=udp via sip:192.168.99.21:59567...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:61527;transport=udp via sip:192.168.99.145:61527...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56841;transport=udp via sip:192.168.99.145:56841...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:50394;transport=udp via sip:192.168.99.21:50394...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:65370;transport=udp via sip:192.168.99.21:65370...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:49919;transport=udp via sip:192.168.99.145:49919...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:59023;transport=udp via sip:192.168.99.145:59023...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56624;transport=udp via sip:192.168.99.145:56624...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:49915;transport=udp via sip:192.168.99.21:49915...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:59567;transport=udp via sip:192.168.99.21:59567...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:61527;transport=udp via sip:192.168.99.145:61527...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56841;transport=udp via sip:192.168.99.145:56841...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:50394;transport=udp via sip:192.168.99.21:50394...
24(3019) ERROR: <script>: OPTIONS to sip:bob at 192.168.99.21:65370;transport=udp via sip:192.168.99.21:65370...
17(2986) ERROR: <script>:   Unregistering sip:alice at 192.168.99.145:49919;transport=udp;alias=192.168.99.145~49919~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:529]: w_unregister(): URI: sip:alice at 192.168.99.145:49919;transport=udp;alias=192.168.99.145~49919~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:536]: w_unregister(): Received-Host: 192.168.99.145
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:543]: w_unregister(): Received-Port: 49919
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact(): Searching for contact with AOR [sip:alice at 192.168.99.145:49919;transport=udp;alias=192.168.99.145~49919~1] in P-CSCF usrloc based on VIA [1://192.168.99.145:49919] Received [1://192.168.99.145:49919], Search flag is 1
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:463]: get_pcontact(): Have an AOR to search for
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:468]: get_pcontact(): checking for rinstance17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:480]: get_pcontact(): no rinstance param
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:503]: get_pcontact(): get_pcontact slot is [428]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:61527;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:61527;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:49919;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:49919]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:49919]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:519]: get_pcontact(): found contact with URI [sip:alice at 192.168.99.145:49919;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
17(2986) DEBUG: ims_registrar_pcscf [service_routes.c:788]: pcscf_unregister(): Updating contact [sip:alice at 192.168.99.145:49919;transport=udp]: setting state to PCONTACT_DEREG_PENDING_PUBLISH
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:133]: db_update_pcontact(): updating pcontact: sip:alice at 192.168.99.145:49919;transport=udp
17(2986) DEBUG: <core> [core/mem/q_malloc.c:368]: qm_malloc(): qm_malloc(0xb6d83008, 33) called from ims_usrloc_pcscf: usrloc_db.c: service_routes_as_string(589)
17(2986) DEBUG: <core> [core/mem/q_malloc.c:413]: qm_malloc(): qm_malloc(0xb6d83008, 36) returns address 0xb6e84238 frag. 0xb6e8421c (size=96) on 1 -th hit
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:177]: db_update_pcontact(): Trying to set rx session id: 
17(2986) DEBUG: <core> [core/mem/q_malloc.c:368]: qm_malloc(): qm_malloc(0xb6d83008, 25) called from ims_usrloc_pcscf: usrloc_db.c: impus_as_string(550)
17(2986) DEBUG: <core> [core/mem/q_malloc.c:413]: qm_malloc(): qm_malloc(0xb6d83008, 28) returns address 0xb6e84374 frag. 0xb6e84358 (size=32) on 1 -th hit
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
17(2986) ERROR: <script>:   Unregistering sip:alice at 192.168.99.145:59023;transport=udp;alias=192.168.99.145~59023~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:529]: w_unregister(): URI: sip:alice at 192.168.99.145:59023;transport=udp;alias=192.168.99.145~59023~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:536]: w_unregister(): Received-Host: 192.168.99.145
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:543]: w_unregister(): Received-Port: 59023
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact(): Searching for contact with AOR [sip:alice at 192.168.99.145:59023;transport=udp;alias=192.168.99.145~59023~1] in P-CSCF usrloc based on VIA [1://192.168.99.145:59023] Received [1://192.168.99.145:59023], Search flag is 1
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:463]: get_pcontact(): Have an AOR to search for
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:468]: get_pcontact(): checking for rinstance17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:480]: get_pcontact(): no rinstance param
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:503]: get_pcontact(): get_pcontact slot is [428]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:519]: get_pcontact(): found contact with URI [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
17(2986) DEBUG: ims_registrar_pcscf [service_routes.c:788]: pcscf_unregister(): Updating contact [sip:alice at 192.168.99.145:59023;transport=udp]: setting state to PCONTACT_DEREG_PENDING_PUBLISH
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:133]: db_update_pcontact(): updating pcontact: sip:alice at 192.168.99.145:59023;transport=udp
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:177]: db_update_pcontact(): Trying to set rx session id: 
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
17(2986) ERROR: <script>:   Unregistering sip:alice at 192.168.99.145:56624;transport=udp;alias=192.168.99.145~56624~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:529]: w_unregister(): URI: sip:alice at 192.168.99.145:56624;transport=udp;alias=192.168.99.145~56624~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:536]: w_unregister(): Received-Host: 192.168.99.145
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:543]: w_unregister(): Received-Port: 56624
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact(): Searching for contact with AOR [sip:alice at 192.168.99.145:56624;transport=udp;alias=192.168.99.145~56624~1] in P-CSCF usrloc based on VIA [1://192.168.99.145:56624] Received [1://192.168.99.145:56624], Search flag is 1
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:463]: get_pcontact(): Have an AOR to search for
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:468]: get_pcontact(): checking for rinstance17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:480]: get_pcontact(): no rinstance param
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:503]: get_pcontact(): get_pcontact slot is [428]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:61527;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:61527;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:519]: get_pcontact(): found contact with URI [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
17(2986) DEBUG: ims_registrar_pcscf [service_routes.c:788]: pcscf_unregister(): Updating contact [sip:alice at 192.168.99.145:56624;transport=udp]: setting state to PCONTACT_DEREG_PENDING_PUBLISH
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:133]: db_update_pcontact(): updating pcontact: sip:alice at 192.168.99.145:56624;transport=udp
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:177]: db_update_pcontact(): Trying to set rx session id: 
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:193]: db_update_pcontact(): no existing rows for an update... doing insert
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
17(2986) ERROR: <script>:   Unregistering sip:bob at 192.168.99.21:49915;transport=udp;alias=192.168.99.21~49915~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:529]: w_unregister(): URI: sip:bob at 192.168.99.21:49915;transport=udp;alias=192.168.99.21~49915~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:536]: w_unregister(): Received-Host: 192.168.99.21
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:543]: w_unregister(): Received-Port: 49915
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact(): Searching for contact with AOR [sip:bob at 192.168.99.21:49915;transport=udp;alias=192.168.99.21~49915~1] in P-CSCF usrloc based on VIA [1://192.168.99.21:49915] Received [1://192.168.99.21:49915], Search flag is 1
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:463]: get_pcontact(): Have an AOR to search for
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:468]: get_pcontact(): checking for rinstance17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:480]: get_pcontact(): no rinstance param
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:503]: get_pcontact(): get_pcontact slot is [292]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:519]: get_pcontact(): found contact with URI [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [292]
17(2986) DEBUG: ims_registrar_pcscf [service_routes.c:788]: pcscf_unregister(): Updating contact [sip:bob at 192.168.99.21:49915;transport=udp]: setting state to PCONTACT_DEREG_PENDING_PUBLISH
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:133]: db_update_pcontact(): updating pcontact: sip:bob at 192.168.99.21:49915;transport=udp
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:177]: db_update_pcontact(): Trying to set rx session id: 
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:193]: db_update_pcontact(): no existing rows for an update... doing insert
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [292]
17(2986) ERROR: <script>:   Unregistering sip:bob at 192.168.99.21:59567;transport=udp;alias=192.168.99.21~59567~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:529]: w_unregister(): URI: sip:bob at 192.168.99.21:59567;transport=udp;alias=192.168.99.21~59567~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:536]: w_unregister(): Received-Host: 192.168.99.21
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:543]: w_unregister(): Received-Port: 59567
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact(): Searching for contact with AOR [sip:bob at 192.168.99.21:59567;transport=udp;alias=192.168.99.21~59567~1] in P-CSCF usrloc based on VIA [1://192.168.99.21:59567] Received [1://192.168.99.21:59567], Search flag is 1
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:463]: get_pcontact(): Have an AOR to search for
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:468]: get_pcontact(): checking for rinstance17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:480]: get_pcontact(): no rinstance param
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:503]: get_pcontact(): get_pcontact slot is [292]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:50394;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:50394;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:65370;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:65370]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:65370]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:50394;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:50394;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:65370;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:65370]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:65370]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:59567;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:59567]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:59567]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:519]: get_pcontact(): found contact with URI [sip:bob at 192.168.99.21:59567;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [292]
17(2986) DEBUG: ims_registrar_pcscf [service_routes.c:788]: pcscf_unregister(): Updating contact [sip:bob at 192.168.99.21:59567;transport=udp]: setting state to PCONTACT_DEREG_PENDING_PUBLISH
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:133]: db_update_pcontact(): updating pcontact: sip:bob at 192.168.99.21:59567;transport=udp
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:177]: db_update_pcontact(): Trying to set rx session id: 
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:193]: db_update_pcontact(): no existing rows for an update... doing insert
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [292]
17(2986) ERROR: <script>:   Unregistering sip:alice at 192.168.99.145:61527;transport=udp;alias=192.168.99.145~61527~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:529]: w_unregister(): URI: sip:alice at 192.168.99.145:61527;transport=udp;alias=192.168.99.145~61527~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:536]: w_unregister(): Received-Host: 192.168.99.145
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:543]: w_unregister(): Received-Port: 61527
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact(): Searching for contact with AOR [sip:alice at 192.168.99.145:61527;transport=udp;alias=192.168.99.145~61527~1] in P-CSCF usrloc based on VIA [1://192.168.99.145:61527] Received [1://192.168.99.145:61527], Search flag is 1
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:463]: get_pcontact(): Have an AOR to search for
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:468]: get_pcontact(): checking for rinstance17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:480]: get_pcontact(): no rinstance param
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:503]: get_pcontact(): get_pcontact slot is [428]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:61527;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:519]: get_pcontact(): found contact with URI [sip:alice at 192.168.99.145:61527;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
17(2986) DEBUG: ims_registrar_pcscf [service_routes.c:788]: pcscf_unregister(): Updating contact [sip:alice at 192.168.99.145:61527;transport=udp]: setting state to PCONTACT_DEREG_PENDING_PUBLISH
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:133]: db_update_pcontact(): updating pcontact: sip:alice at 192.168.99.145:61527;transport=udp
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:177]: db_update_pcontact(): Trying to set rx session id: 
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:193]: db_update_pcontact(): no existing rows for an update... doing insert
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
17(2986) ERROR: <script>:   Unregistering sip:bob at 192.168.99.21:50394;transport=udp;alias=192.168.99.21~50394~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:529]: w_unregister(): URI: sip:bob at 192.168.99.21:50394;transport=udp;alias=192.168.99.21~50394~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:536]: w_unregister(): Received-Host: 192.168.99.21
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:543]: w_unregister(): Received-Port: 50394
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact(): Searching for contact with AOR [sip:bob at 192.168.99.21:50394;transport=udp;alias=192.168.99.21~50394~1] in P-CSCF usrloc based on VIA [1://192.168.99.21:50394] Received [1://192.168.99.21:50394], Search flag is 1
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:463]: get_pcontact(): Have an AOR to search for
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:468]: get_pcontact(): checking for rinstance17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:480]: get_pcontact(): no rinstance param
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:503]: get_pcontact(): get_pcontact slot is [292]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:50394;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:519]: get_pcontact(): found contact with URI [sip:bob at 192.168.99.21:50394;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [292]
17(2986) DEBUG: ims_registrar_pcscf [service_routes.c:788]: pcscf_unregister(): Updating contact [sip:bob at 192.168.99.21:50394;transport=udp]: setting state to PCONTACT_DEREG_PENDING_PUBLISH
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:133]: db_update_pcontact(): updating pcontact: sip:bob at 192.168.99.21:50394;transport=udp
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:177]: db_update_pcontact(): Trying to set rx session id: 
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:193]: db_update_pcontact(): no existing rows for an update... doing insert
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [292]
17(2986) ERROR: <script>:   Unregistering sip:bob at 192.168.99.21:65370;transport=udp;alias=192.168.99.21~65370~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:529]: w_unregister(): URI: sip:bob at 192.168.99.21:65370;transport=udp;alias=192.168.99.21~65370~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:536]: w_unregister(): Received-Host: 192.168.99.21
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:543]: w_unregister(): Received-Port: 65370
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact(): Searching for contact with AOR [sip:bob at 192.168.99.21:65370;transport=udp;alias=192.168.99.21~65370~1] in P-CSCF usrloc based on VIA [1://192.168.99.21:65370] Received [1://192.168.99.21:65370], Search flag is 1
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:463]: get_pcontact(): Have an AOR to search for
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:468]: get_pcontact(): checking for rinstance17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:480]: get_pcontact(): no rinstance param
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:503]: get_pcontact(): get_pcontact slot is [292]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:49915;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:49915]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:50394;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:50394;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:50394]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892500260], aor [sip:bob at 192.168.99.21:65370;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.21:65370]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.21:65370]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:519]: get_pcontact(): found contact with URI [sip:bob at 192.168.99.21:65370;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [292]
17(2986) DEBUG: ims_registrar_pcscf [service_routes.c:788]: pcscf_unregister(): Updating contact [sip:bob at 192.168.99.21:65370;transport=udp]: setting state to PCONTACT_DEREG_PENDING_PUBLISH
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:133]: db_update_pcontact(): updating pcontact: sip:bob at 192.168.99.21:65370;transport=udp
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:177]: db_update_pcontact(): Trying to set rx session id: 
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:193]: db_update_pcontact(): no existing rows for an update... doing insert
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892500260]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [292]
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56841;transport=udp via sip:192.168.99.145:56841...
13(2977) ERROR: <script>: REGISTER (sip:alice at koffee-ims.in (192.168.99.145:56841) to sip:alice at koffee-ims.in, 18311620-ffe8-dccb-89e3-8eb88ba83f38)
13(2977) INFO: rr [rr_mod.c:443]: pv_get_route_uri_f(): No route header present.
13(2977) INFO: <script>: Register Request came, sip:koffee-ims.in
14(2979) ERROR: <script>: REGISTER (sip:alice at koffee-ims.in (192.168.99.145:56841) to sip:alice at koffee-ims.in, 18311620-ffe8-dccb-89e3-8eb88ba83f38)
14(2979) INFO: rr [rr_mod.c:443]: pv_get_route_uri_f(): No route header present.
14(2979) INFO: <script>: Register Request came, sip:koffee-ims.in
11(2974) ERROR: <script>: REGISTER (sip:alice at koffee-ims.in (192.168.99.145:56841) to sip:alice at koffee-ims.in, 18311620-ffe8-dccb-89e3-8eb88ba83f38)
11(2974) INFO: rr [rr_mod.c:443]: pv_get_route_uri_f(): No route header present.
11(2974) INFO: <script>: Register Request came, sip:koffee-ims.in
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
 9(2968) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
 8(2967) ERROR: <script>: REGISTER (sip:alice at koffee-ims.in (192.168.99.145:56841) to sip:alice at koffee-ims.in, 18311620-ffe8-dccb-89e3-8eb88ba83f38)
 8(2967) INFO: rr [rr_mod.c:443]: pv_get_route_uri_f(): No route header present.
 8(2967) INFO: <script>: Register Request came, sip:koffee-ims.in
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
 5(2958) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
10(2972) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
15(2982) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
 7(2965) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
 1(2952) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
12(2975) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
 5(2958) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
 5(2958) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
 5(2958) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
 7(2965) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
 1(2952) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
 9(2968) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
12(2975) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
12(2975) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
 5(2958) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
15(2982) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
10(2972) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
 7(2965) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
 7(2965) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
12(2975) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
 9(2968) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
 5(2958) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
15(2982) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
10(2972) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
 7(2965) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
 1(2952) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
 1(2952) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
 1(2952) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
 1(2952) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
 1(2952) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
12(2975) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
12(2975) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
16(2983) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
12(2975) ERROR: <script>: REGISTER (sip:alice at koffee-ims.in (192.168.99.145:60101) to sip:alice at koffee-ims.in, 938fd9fe-d6ac-bdb9-3464-32078edb2643)
12(2975) INFO: rr [rr_mod.c:443]: pv_get_route_uri_f(): No route header present.
12(2975) INFO: <script>: Register Request came, sip:koffee-ims.in
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
15(2982) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
11(2974) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
 4(2956) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
12(2975) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
 9(2968) ERROR: <script>: SUBSCRIBE (sip:alice at koffee-ims.in (192.168.99.145:60101) to sip:alice at koffee-ims.in, aabe7050-8a8c-1400-8376-88b4e224caa7)
 9(2968) INFO: siputils [chargingvector.c:429]: sip_handle_pcv(): Generated PCV header P-Charging-Vector: icid-value=4956537F000101980B00004700000000; icid-generated-at=192.168.99.140
10(2972) ERROR: <script>: SUBSCRIBE (sip:alice at koffee-ims.in (192.168.99.145:60101) to sip:alice at koffee-ims.in, 33164750-32dd-aa1a-9822-12767ffec999)
 1(2952) ERROR: <script>: SUBSCRIBE (sip:alice at koffee-ims.in (192.168.99.145:60101) to sip:bob at koffee-ims.in, bb9e6572-6788-77c7-3288-ed897ffe9ccc)
10(2972) INFO: siputils [chargingvector.c:429]: sip_handle_pcv(): Generated PCV header P-Charging-Vector: icid-value=4956537F0001019C0B00004700000000; icid-generated-at=192.168.99.140
 1(2952) INFO: siputils [chargingvector.c:429]: sip_handle_pcv(): Generated PCV header P-Charging-Vector: icid-value=4956537F000101880B00004700000000; icid-generated-at=192.168.99.140
 7(2965) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, aabe7050-8a8c-1400-8376-88b4e224caa7)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:pcscf.koffee-ims.in, 7ffbfdc8-3018 at 192.168.99.140)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
 6(2961) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
13(2977) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
 8(2967) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9dba2674-8a9d-4502-4813-59e82734de78)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, cfab0233-f8ba-c712-2654-8de9752eb9c8)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 0bbf6545-bfba-21d7-2550-ccf41f17bfcf)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ee8ba660-fc8a-5714-7864-dae90252b7df)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ff17a25-69fc-2522-6584-e9fe5f5eb688)
15(2982) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, ae0a426b-7b89-6113-1084-d8984320dcde)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, df1cb66a-7bf9-7653-5267-e9ca7346c96d)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e10d1252-7fbf-5173-5122-b8ed3345f78a)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 8ecc2b40-fdc7-c252-3225-4abd722789af)
15(2982) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, a88c11a5-fab9-6d62-2469-98f8e0006efe)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, e1e80276-afff-70d5-5322-ffbc45548a7c)
 3(2954) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 91cd120a-afcc-c615-3958-f5ba177569aa)
 2(2953) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, eba80106-7baf-7531-2140-9ec8431ebcac)
15(2982) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 9eae6612-cb88-0177-2697-e95d0575afbb)
14(2979) ERROR: <script>: NOTIFY (sip:alice at koffee-ims.in (192.168.99.140:6060) to sip:alice at koffee-ims.in, 1ddb6070-cee7-4150-6504-defa4453cabe)
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56841;transport=udp via sip:192.168.99.145:56841...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56841;transport=udp via sip:192.168.99.145:56841...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56841;transport=udp via sip:192.168.99.145:56841...
24(3019) ERROR: <script>: OPTIONS to sip:alice at 192.168.99.145:56841;transport=udp via sip:192.168.99.145:56841...
17(2986) ERROR: <script>:   Unregistering sip:alice at 192.168.99.145:56841;transport=udp;alias=192.168.99.145~56841~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:529]: w_unregister(): URI: sip:alice at 192.168.99.145:56841;transport=udp;alias=192.168.99.145~56841~1
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:536]: w_unregister(): Received-Host: 192.168.99.145
17(2986) DEBUG: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:543]: w_unregister(): Received-Port: 56841
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:459]: get_pcontact(): Searching for contact with AOR [sip:alice at 192.168.99.145:56841;transport=udp;alias=192.168.99.145~56841~1] in P-CSCF usrloc based on VIA [1://192.168.99.145:56841] Received [1://192.168.99.145:56841], Search flag is 1
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:463]: get_pcontact(): Have an AOR to search for
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:468]: get_pcontact(): checking for rinstance17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:480]: get_pcontact(): no rinstance param
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:503]: get_pcontact(): get_pcontact slot is [428]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:61527;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:61527;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:59023;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:59023]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:49919;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:49919]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:49919]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56624;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56624]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:61527;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:61527]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:507]: get_pcontact(): comparing contact with aorhash [2892513196], aor [sip:alice at 192.168.99.145:56841;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:508]: get_pcontact():   contact host [192.168.99.145:56841]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:509]: get_pcontact(): contact received [1:192.168.99.145:56841]
17(2986) DEBUG: ims_usrloc_pcscf [udomain.c:519]: get_pcontact(): found contact with URI [sip:alice at 192.168.99.145:56841;transport=udp]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
17(2986) DEBUG: ims_registrar_pcscf [service_routes.c:788]: pcscf_unregister(): Updating contact [sip:alice at 192.168.99.145:56841;transport=udp]: setting state to PCONTACT_DEREG_PENDING_PUBLISH
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:133]: db_update_pcontact(): updating pcontact: sip:alice at 192.168.99.145:56841;transport=udp
17(2986) DEBUG: ims_usrloc_pcscf [usrloc_db.c:177]: db_update_pcontact(): Trying to set rx session id: 
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:148]: get_aor_hash(): Returning hash: [2892513196]
17(2986) DEBUG: ims_usrloc_pcscf [usrloc.c:139]: get_hash_slot(): Returning hash slot: [428]
 9(2968) ERROR: <script>: INVITE (sip:alice at koffee-ims.in (192.168.99.145:60101) to sip:bob at koffee-ims.in, 74178fce-d298-0315-ecfe-5537f7dfb7c9)
 9(2968) INFO: siputils [chargingvector.c:429]: sip_handle_pcv(): Generated PCV header P-Charging-Vector: icid-value=4956537F000101980B0000D401000000; icid-generated-at=192.168.99.140
 5(2958) ERROR: <script>: ACK (sip:alice at koffee-ims.in (192.168.99.145:60101) to sip:bob at koffee-ims.in, 74178fce-d298-0315-ecfe-5537f7dfb7c9)
 5(2958) WARNING: tm [t_lookup.c:1465]: t_unref(): script writer didn't release transaction


-------------- next part --------------
koffee at debian-km:~$ su
Password: 
root at debian-km:/home/koffee# kamailio -f /usr/local/etc/scscf/kamailio.cfg 
loading modules under config path: /usr/local/src/kamailio-5.0/kamailio/src/modules/
 0(3143) INFO: <core> [core/sctp_core.c:75]: sctp_core_check_support(): SCTP API not enabled - if you want to use it, load sctp module
Listening on 
             udp: 192.168.99.140 [192.168.99.140]:6060
Aliases: 
             *: scscf.koffee-ims.in:*

 0(3145) INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded
 0(3145) INFO: rr [rr_mod.c:175]: mod_init(): outbound module not available
 0(3145) INFO: pike [pike.c:99]: pike_init(): PIKE - initializing
 0(3145) INFO: pike [ip_tree.c:81]: init_lock_set(): probing 256 set size
 0(3145) INFO: jsonrpcs [jsonrpcs_sock.c:197]: jsonrpc_dgram_mod_init(): the socket /var/run/kamailio/kamailio_rpc.sock already exists, trying to delete it...
 0(3145) INFO: ims_usrloc_scscf [hslot.c:69]: ul_init_locks(): locks array size 512
 0(3145) INFO: ims_usrloc_scscf [contact_hslot.c:67]: init_contacts_locks(): locks array size 512
 0(3145) INFO: ims_usrloc_scscf [hslot_sp.c:70]: subs_init_locks(): locks array size 512
 0(3145) INFO: <core> [core/udp_server.c:153]: probe_max_receive_buffer(): SO_RCVBUF is initially 163840
 0(3145) INFO: <core> [core/udp_server.c:203]: probe_max_receive_buffer(): SO_RCVBUF is finally 327680
 0(3145) INFO: cdp [cdp_mod.c:242]: cdp_child_init(): CDiameterPeer child starting ...
18(3172) INFO: jsonrpcs [jsonrpcs_sock.c:429]: jsonrpc_dgram_process(): a new child 0/3172
 0(3145) INFO: cdp [cdp_mod.c:244]: cdp_child_init(): ... CDiameterPeer child started
22(3181) INFO: cdp [worker.c:332]: worker_process(): [3] Worker process started...
20(3177) INFO: cdp [worker.c:332]: worker_process(): [1] Worker process started...
23(3182) INFO: cdp [worker.c:332]: worker_process(): [4] Worker process started...
26(3186) INFO: cdp [worker.c:332]: worker_process(): [7] Worker process started...
24(3183) INFO: cdp [worker.c:332]: worker_process(): [5] Worker process started...
25(3184) INFO: cdp [worker.c:332]: worker_process(): [6] Worker process started...
28(3189) INFO: cdp [worker.c:332]: worker_process(): [9] Worker process started...
19(3173) INFO: cdp [worker.c:332]: worker_process(): [0] Worker process started...
30(3193) INFO: cdp [worker.c:332]: worker_process(): [11] Worker process started...
27(3187) INFO: cdp [worker.c:332]: worker_process(): [8] Worker process started...
29(3190) INFO: cdp [worker.c:332]: worker_process(): [10] Worker process started...
16(3168) INFO: ctl [io_listener.c:210]: io_listen_loop(): io_listen_loop: using epoll_lt as the io watch method (auto detected)
21(3180) INFO: cdp [worker.c:332]: worker_process(): [2] Worker process started...
35(3207) INFO: cdp [receiver.c:450]: receiver_process(): receiver_process(): [] Receiver process doing init on new process...
35(3207) INFO: cdp [receiver.c:455]: receiver_process(): receiver_process(): [] Receiver process starting up...
36(3208) INFO: cdp [receiver.c:450]: receiver_process(): receiver_process(): [hss.koffee-ims.in] Receiver process doing init on new process...
36(3208) INFO: cdp [receiver.c:184]: add_serviced_peer(): add_serviced_peer(): Adding serviced_peer_t to receiver for peer [hss.koffee-ims.in]
36(3208) INFO: cdp [receiver.c:455]: receiver_process(): receiver_process(): [hss.koffee-ims.in] Receiver process starting up...
33(3205) INFO: cdp [worker.c:332]: worker_process(): [14] Worker process started...
34(3206) INFO: cdp [worker.c:332]: worker_process(): [15] Worker process started...
37(3209) INFO: cdp [acceptor.c:81]: acceptor_process(): Acceptor process starting up...
37(3209) WARNING: cdp [tcp_accept.c:121]: create_socket(): create_socket(): Trying to open/bind/listen on 192.168.99.140 port 3870
37(3209) WARNING: cdp [tcp_accept.c:146]: create_socket(): create_socket(): Successful socket open/bind/listen on 192.168.99.140 port 3870
37(3209) INFO: cdp [acceptor.c:95]: acceptor_process(): Acceptor opened sockets. Entering accept loop ...
root at debian-km:/home/koffee# 38(3210) INFO: cdp [timer.c:205]: timer_process(): Timer process starting up...
31(3196) INFO: cdp [worker.c:332]: worker_process(): [12] Worker process started...
32(3204) INFO: cdp [worker.c:332]: worker_process(): [13] Worker process started...
38(3210) INFO: cdp [peerstatemachine.c:525]: I_Snd_Conn_Req(): I_Snd_Conn_Req(): Peer hss.koffee-ims.in 
38(3210) INFO: cdp [receiver.c:869]: peer_connect(): peer_connect(): Trying to connect to 192.168.99.140 port 3868
38(3210) INFO: cdp [receiver.c:937]: peer_connect(): peer_connect(): Peer hss.koffee-ims.in:3868 connected
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086847
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086847
 2(3148) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086857
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086857
 5(3152) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086867
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086867
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086877
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086877
 4(3150) ERROR: <script>: Inside route{........}
 3(3149) ERROR: <script>: Inside route{........}
 3(3149) ERROR: <script>: ALGORITHM IS [<null>] and User-Agent is [IM-client/OMA1.0 Boghe-Win32/v2.0.153.836]
 3(3149) DEBUG: ims_auth [authorize.c:734]: authenticate(): Running authenticate, is_proxy_auth=0
 3(3149) DEBUG: ims_auth [authorize.c:754]: authenticate(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
 3(3149) DEBUG: ims_auth [authorize.c:792]: authenticate(): Nonce or response missing: nonce len [0], response16 len[0]
 3(3149) DEBUG: ims_auth [authorize.c:299]: challenge(): Looking for route block [REG_MAR_REPLY]
 3(3149) INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [-2]
 3(3149) DEBUG: ims_auth [authorize.c:323]: challenge(): Need to challenge for realm [koffee-ims.in]
 3(3149) DEBUG: ims_auth [authorize.c:330]: challenge(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
 3(3149) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
 3(3149) DEBUG: ims_auth [authorize.c:466]: challenge(): Suspending SIP TM transaction
 3(3149) DEBUG: ims_auth [authorize.c:1534]: multimedia_auth_request(): Sending MAR
 3(3149) DEBUG: ims_auth [cxdx_mar.c:549]: cxdx_send_mar(): Successfully sent async diameter
22(3181) INFO: ims_auth [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp (avp_code = 297, vendor_id = 0)
22(3181) DEBUG: ims_auth [authorize.c:1565]: pack_challenge(): setting QOP str used is [, qop="auth,auth-int"]
22(3181) DEBUG: ims_auth [authorize.c:1567]: pack_challenge(): QOP str used is [, qop="auth,auth-int"]
22(3181) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
22(3181) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
22(3181) DEBUG: ims_auth [authorize.c:1689]: add_auth_vector(): Adding auth_vector (status 1) for IMPU sip:alice at koffee-ims.in / IMPI alice at koffee-ims.in (Hash 181)
22(3181) DEBUG: ims_auth [cxdx_mar.c:464]: async_cdp_callback(): DBG:UAR Async CDP callback: ... Done resuming transaction
22(3181) INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [1]
22(3181) DEBUG: ims_auth [cxdx_mar.c:87]: free_saved_transaction_data(): Freeing saved transaction data: async
11(3161) ERROR: <script>: Inside route{........}
11(3161) ERROR: <script>: ALGORITHM IS [MD5] and User-Agent is [IM-client/OMA1.0 Boghe-Win32/v2.0.153.836]
11(3161) DEBUG: ims_auth [authorize.c:734]: authenticate(): Running authenticate, is_proxy_auth=0
11(3161) DEBUG: ims_auth [authorize.c:754]: authenticate(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
11(3161) DEBUG: ims_auth [utils.c:168]: get_nonce_response(): Calling find_credentials with realm [koffee-ims.in]
11(3161) DEBUG: ims_auth [utils.c:57]: ims_find_credentials(): Searching credentials in realm [koffee-ims.in]
11(3161) DEBUG: ims_auth [utils.c:92]: ims_find_credentials(): *hook = 0xb6e4ab4c
11(3161) DEBUG: ims_auth [utils.c:103]: ims_find_credentials(): Credential parsed successfully
11(3161) DEBUG: ims_auth [utils.c:106]: ims_find_credentials(): Comparing realm <koffee-ims.in> and <koffee-ims.in>
11(3161) DEBUG: ims_auth [utils.c:195]: get_nonce_response(): Found nonce response
11(3161) DEBUG: ims_auth [authorize.c:812]: authenticate(): Looking for auth vector based on IMPI: [alice at koffee-ims.in] and IMPU: [sip:alice at koffee-ims.in]
11(3161) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
11(3161) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
11(3161) DEBUG: ims_auth [authorize.c:829]: authenticate(): look for a fresh vector for alice at koffee-ims.in
11(3161) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
11(3161) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
11(3161) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 1 and were looking for 1
11(3161) DEBUG: ims_auth [authorize.c:1072]: get_auth_vector(): Found result
11(3161) INFO: ims_auth [authorize.c:840]: authenticate(): uri=sip:koffee-ims.in nonce=cd77bdb3c75d390135f9b1b85a3323fb response=0fce8aa0593a5c5cfbdfbc0d99b8adf6 qop=auth-int nc=00000001 cnonce=ba4a8eba6cca0e92df35824f36dac6e1 hbody=d41d8cd98f00b204e9800998ecf8427e
11(3161) DEBUG: ims_auth [authorize.c:865]: authenticate(): nc is 00000001, expected: 00000001
11(3161) DEBUG: ims_auth [rfc2617.c:144]: calc_response(): calc_response(_ha1=4802e13f2db32d20d287f397ba099aa6, _nonce=cd77bdb3c75d390135f9b1b85a3323fb, _nc=00000001,_cnonce=ba4a8eba6cca0e92df35824f36dac6e1, _qop=auth-int, _auth_int=1,_method=REGISTER,_uri=sip:koffee-ims.in,_hentity=d41d8cd98f00b204e9800998ecf8427e)
11(3161) DEBUG: ims_auth [rfc2617.c:186]: calc_response(): H(A1) = 4802e13f2db32d20d287f397ba099aa6, H(A2) = 73b9fcf5220c7f9a7e9460a5e50e1172, rspauth = 0fce8aa0593a5c5cfbdfbc0d99b8adf6
11(3161) INFO: ims_auth [authorize.c:892]: authenticate(): UE said: 0fce8aa0593a5c5cfbdfbc0d99b8adf6 and we expect 0fce8aa0593a5c5cfbdfbc0d99b8adf6 ha1 4802e13f2db32d20d287f397ba099aa6 (REGISTER)
11(3161) DEBUG: ims_auth [authorize.c:927]: authenticate(): vector 0xb2060d10 successfully used 1 time(s)
11(3161) DEBUG: ims_auth [authorize.c:930]: authenticate(): vector 0xb2060d10 isn't fresh anymore, recycle it with a new nonce
 8(3158) ERROR: <script>: Inside route{........}
 8(3158) ERROR: <script>: ALGORITHM IS [MD5] and User-Agent is [IM-client/OMA1.0 Boghe-Win32/v2.0.153.836]
 8(3158) DEBUG: ims_auth [authorize.c:734]: authenticate(): Running authenticate, is_proxy_auth=0
 8(3158) DEBUG: ims_auth [authorize.c:754]: authenticate(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
 8(3158) DEBUG: ims_auth [utils.c:168]: get_nonce_response(): Calling find_credentials with realm [koffee-ims.in]
 8(3158) DEBUG: ims_auth [utils.c:57]: ims_find_credentials(): Searching credentials in realm [koffee-ims.in]
 8(3158) DEBUG: ims_auth [utils.c:92]: ims_find_credentials(): *hook = 0xb6e4ab4c
 8(3158) DEBUG: ims_auth [utils.c:103]: ims_find_credentials(): Credential parsed successfully
 8(3158) DEBUG: ims_auth [utils.c:106]: ims_find_credentials(): Comparing realm <koffee-ims.in> and <koffee-ims.in>
 8(3158) DEBUG: ims_auth [utils.c:195]: get_nonce_response(): Found nonce response
 8(3158) DEBUG: ims_auth [authorize.c:812]: authenticate(): Looking for auth vector based on IMPI: [alice at koffee-ims.in] and IMPU: [sip:alice at koffee-ims.in]
 8(3158) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
 8(3158) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
 8(3158) DEBUG: ims_auth [authorize.c:820]: authenticate(): vector 0xb2060d10 is marked for deletion
 8(3158) DEBUG: ims_auth [authorize.c:829]: authenticate(): look for a fresh vector for alice at koffee-ims.in
 8(3158) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
 8(3158) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
 8(3158) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 1
 8(3158) INFO: ims_auth [authorize.c:840]: authenticate(): uri=sip:koffee-ims.in nonce=cd77bdb3c75d390135f9b1b85a3323fb response=0fce8aa0593a5c5cfbdfbc0d99b8adf6 qop=auth-int nc=00000001 cnonce=ba4a8eba6cca0e92df35824f36dac6e1 hbody=d41d8cd98f00b204e9800998ecf8427e
 8(3158) DEBUG: ims_auth [authorize.c:843]: authenticate(): no matching auth vector found - maybe timer expired
 8(3158) DEBUG: ims_auth [authorize.c:299]: challenge(): Looking for route block [REG_MAR_REPLY]
 8(3158) INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [-2]
 8(3158) DEBUG: ims_auth [authorize.c:323]: challenge(): Need to challenge for realm [koffee-ims.in]
 8(3158) DEBUG: ims_auth [authorize.c:330]: challenge(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
 8(3158) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
 8(3158) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
 8(3158) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 0
 8(3158) DEBUG: ims_auth [authorize.c:466]: challenge(): Suspending SIP TM transaction
 8(3158) DEBUG: ims_auth [authorize.c:1534]: multimedia_auth_request(): Sending MAR
 8(3158) DEBUG: ims_auth [cxdx_mar.c:549]: cxdx_send_mar(): Successfully sent async diameter
20(3177) INFO: ims_auth [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp (avp_code = 297, vendor_id = 0)
20(3177) DEBUG: ims_auth [authorize.c:1565]: pack_challenge(): setting QOP str used is [, qop="auth,auth-int"]
20(3177) DEBUG: ims_auth [authorize.c:1567]: pack_challenge(): QOP str used is [, qop="auth,auth-int"]
20(3177) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
20(3177) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
20(3177) DEBUG: ims_auth [authorize.c:1689]: add_auth_vector(): Adding auth_vector (status 1) for IMPU sip:alice at koffee-ims.in / IMPI alice at koffee-ims.in (Hash 181)
20(3177) DEBUG: ims_auth [cxdx_mar.c:464]: async_cdp_callback(): DBG:UAR Async CDP callback: ... Done resuming transaction
20(3177) INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [1]
20(3177) DEBUG: ims_auth [cxdx_mar.c:87]: free_saved_transaction_data(): Freeing saved transaction data: async
 6(3153) ERROR: <script>: Inside route{........}
 6(3153) ERROR: <script>: ALGORITHM IS [MD5] and User-Agent is [IM-client/OMA1.0 Boghe-Win32/v2.0.153.836]
 6(3153) DEBUG: ims_auth [authorize.c:734]: authenticate(): Running authenticate, is_proxy_auth=0
 6(3153) DEBUG: ims_auth [authorize.c:754]: authenticate(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
 6(3153) DEBUG: ims_auth [utils.c:168]: get_nonce_response(): Calling find_credentials with realm [koffee-ims.in]
 6(3153) DEBUG: ims_auth [utils.c:57]: ims_find_credentials(): Searching credentials in realm [koffee-ims.in]
 6(3153) DEBUG: ims_auth [utils.c:92]: ims_find_credentials(): *hook = 0xb6e4ab4c
 6(3153) DEBUG: ims_auth [utils.c:103]: ims_find_credentials(): Credential parsed successfully
 6(3153) DEBUG: ims_auth [utils.c:106]: ims_find_credentials(): Comparing realm <koffee-ims.in> and <koffee-ims.in>
 6(3153) DEBUG: ims_auth [utils.c:195]: get_nonce_response(): Found nonce response
 6(3153) DEBUG: ims_auth [authorize.c:812]: authenticate(): Looking for auth vector based on IMPI: [alice at koffee-ims.in] and IMPU: [sip:alice at koffee-ims.in]
 6(3153) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
 6(3153) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
 6(3153) DEBUG: ims_auth [authorize.c:829]: authenticate(): look for a fresh vector for alice at koffee-ims.in
 6(3153) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
 6(3153) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
 6(3153) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 1 and were looking for 1
 6(3153) DEBUG: ims_auth [authorize.c:1072]: get_auth_vector(): Found result
 6(3153) INFO: ims_auth [authorize.c:840]: authenticate(): uri=sip:koffee-ims.in nonce=c01a3b0a33ce724b273e859778a9170e response=255d289e9f2eb2afb1b9c661388753b8 qop=auth-int nc=00000001 cnonce=e0d8727444e65aeec91b45f690b908ab hbody=d41d8cd98f00b204e9800998ecf8427e
 6(3153) DEBUG: ims_auth [authorize.c:865]: authenticate(): nc is 00000001, expected: 00000001
 6(3153) DEBUG: ims_auth [rfc2617.c:144]: calc_response(): calc_response(_ha1=4802e13f2db32d20d287f397ba099aa6, _nonce=c01a3b0a33ce724b273e859778a9170e, _nc=00000001,_cnonce=e0d8727444e65aeec91b45f690b908ab, _qop=auth-int, _auth_int=1,_method=REGISTER,_uri=sip:koffee-ims.in,_hentity=d41d8cd98f00b204e9800998ecf8427e)
 6(3153) DEBUG: ims_auth [rfc2617.c:186]: calc_response(): H(A1) = 4802e13f2db32d20d287f397ba099aa6, H(A2) = 73b9fcf5220c7f9a7e9460a5e50e1172, rspauth = 255d289e9f2eb2afb1b9c661388753b8
 6(3153) INFO: ims_auth [authorize.c:892]: authenticate(): UE said: 255d289e9f2eb2afb1b9c661388753b8 and we expect 255d289e9f2eb2afb1b9c661388753b8 ha1 4802e13f2db32d20d287f397ba099aa6 (REGISTER)
 6(3153) DEBUG: ims_auth [authorize.c:927]: authenticate(): vector 0xb20649c4 successfully used 1 time(s)
 6(3153) DEBUG: ims_auth [authorize.c:930]: authenticate(): vector 0xb20649c4 isn't fresh anymore, recycle it with a new nonce
11(3161) ERROR: ims_registrar_scscf [save.c:1033]: update_contacts(): Unable to remove contact <sip:alice at 192.168.99.145:56841;transport=udp>
11(3161) INFO: ims_registrar_scscf [cxdx_sar.c:84]: create_return_code(): created AVP successfully : [saa_return_code] - [-2]
11(3161) ERROR: ims_registrar_scscf [save.c:1432]: save(): failed to suspend the TM processing
11(3161) ERROR: tm [t_reply.c:482]: _reply_light(): can't generate 500 reply when a final 401 was sent out
11(3161) ERROR: sl [sl.c:271]: send_reply(): failed to reply stateful (tm)
11(3161) ERROR: ims_registrar_scscf [reply.c:820]: reg_send_reply(): failed to send 500 Server Internal Error
12(3162) ERROR: <script>: Inside route{........}
12(3162) ERROR: <script>: ALGORITHM IS [MD5] and User-Agent is [IM-client/OMA1.0 Boghe-Win32/v2.0.153.836]
12(3162) DEBUG: ims_auth [authorize.c:734]: authenticate(): Running authenticate, is_proxy_auth=0
12(3162) DEBUG: ims_auth [authorize.c:754]: authenticate(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
12(3162) DEBUG: ims_auth [utils.c:168]: get_nonce_response(): Calling find_credentials with realm [koffee-ims.in]
12(3162) DEBUG: ims_auth [utils.c:57]: ims_find_credentials(): Searching credentials in realm [koffee-ims.in]
12(3162) DEBUG: ims_auth [utils.c:92]: ims_find_credentials(): *hook = 0xb6e4ab4c
12(3162) DEBUG: ims_auth [utils.c:103]: ims_find_credentials(): Credential parsed successfully
12(3162) DEBUG: ims_auth [utils.c:106]: ims_find_credentials(): Comparing realm <koffee-ims.in> and <koffee-ims.in>
12(3162) DEBUG: ims_auth [utils.c:195]: get_nonce_response(): Found nonce response
12(3162) DEBUG: ims_auth [authorize.c:812]: authenticate(): Looking for auth vector based on IMPI: [alice at koffee-ims.in] and IMPU: [sip:alice at koffee-ims.in]
12(3162) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
12(3162) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
12(3162) DEBUG: ims_auth [authorize.c:820]: authenticate(): vector 0xb20649c4 is marked for deletion
12(3162) DEBUG: ims_auth [authorize.c:829]: authenticate(): look for a fresh vector for alice at koffee-ims.in
12(3162) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
12(3162) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
12(3162) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 1
12(3162) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 1
12(3162) INFO: ims_auth [authorize.c:840]: authenticate(): uri=sip:koffee-ims.in nonce=c01a3b0a33ce724b273e859778a9170e response=255d289e9f2eb2afb1b9c661388753b8 qop=auth-int nc=00000001 cnonce=e0d8727444e65aeec91b45f690b908ab hbody=d41d8cd98f00b204e9800998ecf8427e
12(3162) DEBUG: ims_auth [authorize.c:843]: authenticate(): no matching auth vector found - maybe timer expired
12(3162) DEBUG: ims_auth [authorize.c:299]: challenge(): Looking for route block [REG_MAR_REPLY]
12(3162) INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [-2]
12(3162) DEBUG: ims_auth [authorize.c:323]: challenge(): Need to challenge for realm [koffee-ims.in]
12(3162) DEBUG: ims_auth [authorize.c:330]: challenge(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
12(3162) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
12(3162) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
12(3162) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 0
12(3162) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 0
12(3162) DEBUG: ims_auth [authorize.c:466]: challenge(): Suspending SIP TM transaction
12(3162) DEBUG: ims_auth [authorize.c:1534]: multimedia_auth_request(): Sending MAR
12(3162) DEBUG: ims_auth [cxdx_mar.c:549]: cxdx_send_mar(): Successfully sent async diameter
23(3182) INFO: ims_auth [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp (avp_code = 297, vendor_id = 0)
23(3182) DEBUG: ims_auth [authorize.c:1565]: pack_challenge(): setting QOP str used is [, qop="auth,auth-int"]
23(3182) DEBUG: ims_auth [authorize.c:1567]: pack_challenge(): QOP str used is [, qop="auth,auth-int"]
23(3182) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
23(3182) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
23(3182) DEBUG: ims_auth [authorize.c:1689]: add_auth_vector(): Adding auth_vector (status 1) for IMPU sip:alice at koffee-ims.in / IMPI alice at koffee-ims.in (Hash 181)
23(3182) DEBUG: ims_auth [cxdx_mar.c:464]: async_cdp_callback(): DBG:UAR Async CDP callback: ... Done resuming transaction
23(3182) INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [1]
23(3182) DEBUG: ims_auth [cxdx_mar.c:87]: free_saved_transaction_data(): Freeing saved transaction data: async
10(3160) ERROR: <script>: Inside route{........}
10(3160) ERROR: <script>: ALGORITHM IS [MD5] and User-Agent is [IM-client/OMA1.0 Boghe-Win32/v2.0.153.836]
10(3160) DEBUG: ims_auth [authorize.c:734]: authenticate(): Running authenticate, is_proxy_auth=0
10(3160) DEBUG: ims_auth [authorize.c:754]: authenticate(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
10(3160) DEBUG: ims_auth [utils.c:168]: get_nonce_response(): Calling find_credentials with realm [koffee-ims.in]
10(3160) DEBUG: ims_auth [utils.c:57]: ims_find_credentials(): Searching credentials in realm [koffee-ims.in]
10(3160) DEBUG: ims_auth [utils.c:92]: ims_find_credentials(): *hook = 0xb6e4ab4c
10(3160) DEBUG: ims_auth [utils.c:103]: ims_find_credentials(): Credential parsed successfully
10(3160) DEBUG: ims_auth [utils.c:106]: ims_find_credentials(): Comparing realm <koffee-ims.in> and <koffee-ims.in>
10(3160) DEBUG: ims_auth [utils.c:195]: get_nonce_response(): Found nonce response
10(3160) DEBUG: ims_auth [authorize.c:812]: authenticate(): Looking for auth vector based on IMPI: [alice at koffee-ims.in] and IMPU: [sip:alice at koffee-ims.in]
10(3160) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
10(3160) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
10(3160) DEBUG: ims_auth [authorize.c:829]: authenticate(): look for a fresh vector for alice at koffee-ims.in
10(3160) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
10(3160) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
10(3160) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 1 and were looking for 1
10(3160) DEBUG: ims_auth [authorize.c:1072]: get_auth_vector(): Found result
10(3160) INFO: ims_auth [authorize.c:840]: authenticate(): uri=sip:koffee-ims.in nonce=4b3a0b4fd6679bf885d6676af202fe9a response=a11c6c5d46f54c772e15bc4fe695a180 qop=auth-int nc=00000001 cnonce=0c32e9989498e1351d5a937afcb92298 hbody=d41d8cd98f00b204e9800998ecf8427e
10(3160) DEBUG: ims_auth [authorize.c:865]: authenticate(): nc is 00000001, expected: 00000001
10(3160) DEBUG: ims_auth [rfc2617.c:144]: calc_response(): calc_response(_ha1=4802e13f2db32d20d287f397ba099aa6, _nonce=4b3a0b4fd6679bf885d6676af202fe9a, _nc=00000001,_cnonce=0c32e9989498e1351d5a937afcb92298, _qop=auth-int, _auth_int=1,_method=REGISTER,_uri=sip:koffee-ims.in,_hentity=d41d8cd98f00b204e9800998ecf8427e)
10(3160) DEBUG: ims_auth [rfc2617.c:186]: calc_response(): H(A1) = 4802e13f2db32d20d287f397ba099aa6, H(A2) = 73b9fcf5220c7f9a7e9460a5e50e1172, rspauth = a11c6c5d46f54c772e15bc4fe695a180
10(3160) INFO: ims_auth [authorize.c:892]: authenticate(): UE said: a11c6c5d46f54c772e15bc4fe695a180 and we expect a11c6c5d46f54c772e15bc4fe695a180 ha1 4802e13f2db32d20d287f397ba099aa6 (REGISTER)
10(3160) DEBUG: ims_auth [authorize.c:927]: authenticate(): vector 0xb206d884 successfully used 1 time(s)
10(3160) DEBUG: ims_auth [authorize.c:930]: authenticate(): vector 0xb206d884 isn't fresh anymore, recycle it with a new nonce
 7(3156) ERROR: <script>: Inside route{........}
 7(3156) ERROR: <script>: ALGORITHM IS [MD5] and User-Agent is [IM-client/OMA1.0 Boghe-Win32/v2.0.153.836]
 7(3156) DEBUG: ims_auth [authorize.c:734]: authenticate(): Running authenticate, is_proxy_auth=0
 7(3156) DEBUG: ims_auth [authorize.c:754]: authenticate(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
 7(3156) DEBUG: ims_auth [utils.c:168]: get_nonce_response(): Calling find_credentials with realm [koffee-ims.in]
 7(3156) DEBUG: ims_auth [utils.c:57]: ims_find_credentials(): Searching credentials in realm [koffee-ims.in]
 7(3156) DEBUG: ims_auth [utils.c:92]: ims_find_credentials(): *hook = 0xb6e4ab4c
 7(3156) DEBUG: ims_auth [utils.c:103]: ims_find_credentials(): Credential parsed successfully
 7(3156) DEBUG: ims_auth [utils.c:106]: ims_find_credentials(): Comparing realm <koffee-ims.in> and <koffee-ims.in>
 7(3156) DEBUG: ims_auth [utils.c:195]: get_nonce_response(): Found nonce response
 7(3156) DEBUG: ims_auth [authorize.c:812]: authenticate(): Looking for auth vector based on IMPI: [alice at koffee-ims.in] and IMPU: [sip:alice at koffee-ims.in]
 7(3156) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
 7(3156) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
 7(3156) DEBUG: ims_auth [authorize.c:820]: authenticate(): vector 0xb206d884 is marked for deletion
 7(3156) DEBUG: ims_auth [authorize.c:829]: authenticate(): look for a fresh vector for alice at koffee-ims.in
 7(3156) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
 7(3156) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
 7(3156) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 1
 7(3156) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 1
 7(3156) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 1
 7(3156) INFO: ims_auth [authorize.c:840]: authenticate(): uri=sip:koffee-ims.in nonce=4b3a0b4fd6679bf885d6676af202fe9a response=a11c6c5d46f54c772e15bc4fe695a180 qop=auth-int nc=00000001 cnonce=0c32e9989498e1351d5a937afcb92298 hbody=d41d8cd98f00b204e9800998ecf8427e
 7(3156) DEBUG: ims_auth [authorize.c:843]: authenticate(): no matching auth vector found - maybe timer expired
 7(3156) DEBUG: ims_auth [authorize.c:299]: challenge(): Looking for route block [REG_MAR_REPLY]
 7(3156) INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [-2]
 7(3156) DEBUG: ims_auth [authorize.c:323]: challenge(): Need to challenge for realm [koffee-ims.in]
 7(3156) DEBUG: ims_auth [authorize.c:330]: challenge(): Checking if REGISTER is authorized for realm [koffee-ims.in]...
 7(3156) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
 7(3156) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
 7(3156) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 0
 7(3156) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 0
 7(3156) DEBUG: ims_auth [authorize.c:1070]: get_auth_vector(): looping through AV status is 2 and were looking for 0
 7(3156) DEBUG: ims_auth [authorize.c:466]: challenge(): Suspending SIP TM transaction
 7(3156) DEBUG: ims_auth [authorize.c:1534]: multimedia_auth_request(): Sending MAR
 7(3156) DEBUG: ims_auth [cxdx_mar.c:549]: cxdx_send_mar(): Successfully sent async diameter
26(3186) INFO: ims_auth [cxdx_avp.c:137]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp (avp_code = 297, vendor_id = 0)
26(3186) DEBUG: ims_auth [authorize.c:1565]: pack_challenge(): setting QOP str used is [, qop="auth,auth-int"]
26(3186) DEBUG: ims_auth [authorize.c:1567]: pack_challenge(): QOP str used is [, qop="auth,auth-int"]
26(3186) DEBUG: ims_auth [authorize.c:1454]: get_auth_userdata(): Searching auth_userdata for IMPU sip:alice at koffee-ims.in (Hash 181)
26(3186) DEBUG: ims_auth [authorize.c:1463]: get_auth_userdata(): Found auth_userdata
26(3186) DEBUG: ims_auth [authorize.c:1689]: add_auth_vector(): Adding auth_vector (status 1) for IMPU sip:alice at koffee-ims.in / IMPI alice at koffee-ims.in (Hash 181)
26(3186) DEBUG: ims_auth [cxdx_mar.c:464]: async_cdp_callback(): DBG:UAR Async CDP callback: ... Done resuming transaction
26(3186) INFO: ims_auth [cxdx_mar.c:79]: create_return_code(): created AVP successfully : [maa_return_code] - [1]
26(3186) DEBUG: ims_auth [cxdx_mar.c:87]: free_saved_transaction_data(): Freeing saved transaction data: async
 6(3153) ERROR: ims_registrar_scscf [save.c:1033]: update_contacts(): Unable to remove contact <sip:alice at 192.168.99.145:56841;transport=udp>
 6(3153) INFO: ims_registrar_scscf [cxdx_sar.c:84]: create_return_code(): created AVP successfully : [saa_return_code] - [-2]
 6(3153) ERROR: ims_registrar_scscf [save.c:1432]: save(): failed to suspend the TM processing
 6(3153) ERROR: tm [t_reply.c:482]: _reply_light(): can't generate 500 reply when a final 401 was sent out
 6(3153) ERROR: sl [sl.c:271]: send_reply(): failed to reply stateful (tm)
 6(3153) ERROR: ims_registrar_scscf [reply.c:820]: reg_send_reply(): failed to send 500 Server Internal Error
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086887
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 1 Exp 64086946  0xb2064b88
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 2 Exp 64087186  0xb206d884
13(3163) DEBUG: ims_auth [authorize.c:210]: reg_await_timer(): ... dropping av 1 - 2
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 2 Exp 64087185  0xb20649c4
13(3163) DEBUG: ims_auth [authorize.c:210]: reg_await_timer(): ... dropping av 1 - 2
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 2 Exp 64087185  0xb2060d10
13(3163) DEBUG: ims_auth [authorize.c:210]: reg_await_timer(): ... dropping av 1 - 2
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086887
10(3160) ERROR: ims_registrar_scscf [save.c:1033]: update_contacts(): Unable to remove contact <sip:alice at 192.168.99.145:56841;transport=udp>
10(3160) INFO: ims_registrar_scscf [cxdx_sar.c:84]: create_return_code(): created AVP successfully : [saa_return_code] - [-2]
10(3160) ERROR: ims_registrar_scscf [save.c:1432]: save(): failed to suspend the TM processing
10(3160) ERROR: tm [t_reply.c:482]: _reply_light(): can't generate 500 reply when a final 401 was sent out
10(3160) ERROR: sl [sl.c:271]: send_reply(): failed to reply stateful (tm)
10(3160) ERROR: ims_registrar_scscf [reply.c:820]: reg_send_reply(): failed to send 500 Server Internal Error
12(3162) ERROR: <script>: Inside route{........}
12(3162) ERROR: <script>: ALGORITHM IS [] and User-Agent is [IM-client/OMA1.0 Boghe-Win32/v2.0.153.836]
12(3162) INFO: ims_registrar_scscf [cxdx_sar.c:84]: create_return_code(): created AVP successfully : [saa_return_code] - [-2]
24(3183) INFO: ims_registrar_scscf [cxdx_avp.c:138]: cxdx_get_avp(): cxdx_get_experimental_result_code: Failed finding avp
24(3183) ERROR: db_mysql [km_dbase.c:128]: db_mysql_submit_query(): driver error on query: Query was empty (1065)
24(3183) ERROR: <core> [db_query.c:181]: db_do_raw_query(): error while submitting query
24(3183) ERROR: ims_usrloc_scscf [usrloc_db.c:1086]: db_link_contact_to_impu(): Unable to link impu-contact in DB - impu [sip:alice at koffee-ims.in], contact [sip:alice at 192.168.99.145:60101;transport=udp]
24(3183) ERROR: ims_usrloc_scscf [impurecord.c:1227]: link_contact_to_impu(): Failed to update DB linking contact [sip:alice at 192.168.99.145:60101;transport=udp] to IMPU [sip:alice at koffee-ims.in]...continuing but db will be out of sync!
 4(3150) ERROR: <script>: Inside route{........}
24(3183) INFO: ims_registrar_scscf [cxdx_sar.c:84]: create_return_code(): created AVP successfully : [saa_return_code] - [1]
 7(3156) ERROR: <script>: Inside route{........}
12(3162) ERROR: <script>: Inside route{........}
 6(3153) ERROR: <script>: Inside route{........}
12(3162) DEBUG: ims_dialog [dlg_handlers.c:826]: dlg_onroute(): No to tag header found --- ignoring... MESSAGE [SUBSCRIBE
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:826]: dlg_onroute(): No to tag header found --- ignoring... MESSAGE [SUBSCRIBE
12(3162) ERROR: <script>: No=1 Before checking sip:orig at .*
 6(3153) ERROR: <script>: No=1 Before checking sip:orig at .*
 6(3153) ERROR: <script>: Orig
 6(3153) ERROR: <script>: No=2 Inside checking sip:orig at .*
 6(3153) DEBUG: ims_dialog [dlg_hash.c:924]: internal_get_dlg(): no dialog callid='bb9e6572-6788-77c7-3288-ed897ffe9ccc' found
 6(3153) DEBUG: ims_dialog [dlg_hash.c:954]: get_dlg(): no dialog callid='bb9e6572-6788-77c7-3288-ed897ffe9ccc' found
12(3162) ERROR: <script>: Orig
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1951]: dlg_get_msg_dialog(): dlg with callid 'bb9e6572-6788-77c7-3288-ed897ffe9ccc' not found
12(3162) ERROR: <script>: No=2 Inside checking sip:orig at .*
12(3162) DEBUG: ims_dialog [dlg_hash.c:924]: internal_get_dlg(): no dialog callid='33164750-32dd-aa1a-9822-12767ffec999' found
12(3162) DEBUG: ims_dialog [dlg_hash.c:954]: get_dlg(): no dialog callid='33164750-32dd-aa1a-9822-12767ffec999' found
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1951]: dlg_get_msg_dialog(): dlg with callid '33164750-32dd-aa1a-9822-12767ffec999' not found
12(3162) INFO: ims_isc [ims_isc_mod.c:233]: isc_match_filter(): Checking triggers
 6(3153) INFO: ims_isc [ims_isc_mod.c:233]: isc_match_filter(): Checking triggers
11(3161) ERROR: <script>: Inside route{........}
 6(3153) ERROR: <script>: No=3 Inside checking sip:After route
12(3162) ERROR: <script>: No=3 Inside checking sip:After route
 8(3158) ERROR: <script>: Inside route{........}
 8(3158) ERROR: <script>: No=1 Before checking sip:orig at .*
 8(3158) DEBUG: ims_dialog [dlg_profile.c:596]: is_dlg_in_profile(): Getting current dialog 8(3158) DEBUG: ims_dialog [dlg_hash.c:924]: internal_get_dlg(): no dialog callid='bb9e6572-6788-77c7-3288-ed897ffe9ccc' found
 8(3158) DEBUG: ims_dialog [dlg_hash.c:954]: get_dlg(): no dialog callid='bb9e6572-6788-77c7-3288-ed897ffe9ccc' found
 8(3158) DEBUG: ims_dialog [dlg_handlers.c:1951]: dlg_get_msg_dialog(): dlg with callid 'bb9e6572-6788-77c7-3288-ed897ffe9ccc' not found
 8(3158) DEBUG: ims_dialog [dlg_profile.c:601]: is_dlg_in_profile(): Error: Current dlg is null 8(3158) DEBUG: ims_dialog [dlg_profile.c:596]: is_dlg_in_profile(): Getting current dialog 8(3158) DEBUG: ims_dialog [dlg_hash.c:924]: internal_get_dlg(): no dialog callid='bb9e6572-6788-77c7-3288-ed897ffe9ccc' found
 8(3158) DEBUG: ims_dialog [dlg_hash.c:954]: get_dlg(): no dialog callid='bb9e6572-6788-77c7-3288-ed897ffe9ccc' found
 8(3158) DEBUG: ims_dialog [dlg_handlers.c:1951]: dlg_get_msg_dialog(): dlg with callid 'bb9e6572-6788-77c7-3288-ed897ffe9ccc' not found
 8(3158) DEBUG: ims_dialog [dlg_profile.c:601]: is_dlg_in_profile(): Error: Current dlg is null 8(3158) ERROR: <script>: No=9 Terminating ---403  Forbidden - Domain not served 
 5(3152) ERROR: <script>: Inside route{........}
 5(3152) ERROR: <script>: No=1 Before checking sip:orig at .*
 5(3152) DEBUG: ims_dialog [dlg_profile.c:596]: is_dlg_in_profile(): Getting current dialog 5(3152) DEBUG: ims_dialog [dlg_hash.c:924]: internal_get_dlg(): no dialog callid='33164750-32dd-aa1a-9822-12767ffec999' found
 5(3152) DEBUG: ims_dialog [dlg_hash.c:954]: get_dlg(): no dialog callid='33164750-32dd-aa1a-9822-12767ffec999' found
 5(3152) DEBUG: ims_dialog [dlg_handlers.c:1951]: dlg_get_msg_dialog(): dlg with callid '33164750-32dd-aa1a-9822-12767ffec999' not found
 5(3152) DEBUG: ims_dialog [dlg_profile.c:601]: is_dlg_in_profile(): Error: Current dlg is null 5(3152) DEBUG: ims_dialog [dlg_profile.c:596]: is_dlg_in_profile(): Getting current dialog 5(3152) DEBUG: ims_dialog [dlg_hash.c:924]: internal_get_dlg(): no dialog callid='33164750-32dd-aa1a-9822-12767ffec999' found
 5(3152) DEBUG: ims_dialog [dlg_hash.c:954]: get_dlg(): no dialog callid='33164750-32dd-aa1a-9822-12767ffec999' found
 5(3152) DEBUG: ims_dialog [dlg_handlers.c:1951]: dlg_get_msg_dialog(): dlg with callid '33164750-32dd-aa1a-9822-12767ffec999' not found
 5(3152) DEBUG: ims_dialog [dlg_profile.c:601]: is_dlg_in_profile(): Error: Current dlg is null 5(3152) ERROR: <script>: No=9 Terminating ---403  Forbidden - Domain not served 
 2(3148) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086897
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 1 Exp 64086946  0xb2064b88
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086897
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086907
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 1 Exp 64086946  0xb2064b88
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086907
 1(3147) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086917
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 1 Exp 64086946  0xb2064b88
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086917
 4(3150) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086927
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 1 Exp 64086946  0xb2064b88
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086927
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086937
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 1 Exp 64086946  0xb2064b88
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086937
 6(3153) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086947
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:204]: reg_await_timer(): .. AV    1 - 1 Exp 64086946  0xb2064b88
13(3163) DEBUG: ims_auth [authorize.c:210]: reg_await_timer(): ... dropping av 1 - 1
13(3163) DEBUG: ims_auth [authorize.c:221]: reg_await_timer(): ... started empty aud drop timer
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086947
 2(3148) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086957
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086957
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086967
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086967
11(3161) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086977
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086977
10(3160) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086987
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086987
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64086997
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64086997
 7(3156) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64087007
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64087007
 9(3159) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64087017
13(3163) DEBUG: ims_auth [authorize.c:199]: reg_await_timer(): Slot  181 <alice at koffee-ims.in>
13(3163) DEBUG: ims_auth [authorize.c:225]: reg_await_timer(): ... dropping aud 
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64087017
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64087027
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64087027
 5(3152) ERROR: <script>: Inside route{........}
12(3162) ERROR: <script>: Inside route{........}
12(3162) DEBUG: ims_dialog [dlg_handlers.c:826]: dlg_onroute(): No to tag header found --- ignoring... MESSAGE [INVITE
12(3162) ERROR: <script>: No=1 Before checking sip:orig at .*
12(3162) ERROR: <script>: Orig
12(3162) ERROR: <script>: No=2 Inside checking sip:orig at .*
12(3162) DEBUG: ims_dialog [dlg_hash.c:924]: internal_get_dlg(): no dialog callid='74178fce-d298-0315-ecfe-5537f7dfb7c9' found
12(3162) DEBUG: ims_dialog [dlg_hash.c:954]: get_dlg(): no dialog callid='74178fce-d298-0315-ecfe-5537f7dfb7c9' found
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1951]: dlg_get_msg_dialog(): dlg with callid '74178fce-d298-0315-ecfe-5537f7dfb7c9' not found
12(3162) DEBUG: ims_dialog [dlg_handlers.c:775]: dlg_onreq(): dialog creation on config flag
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1554]: dlg_new_dialog(): starting dlg_new_dialog and method is [INVITE]
12(3162) DEBUG: ims_dialog [dlg_hash.c:924]: internal_get_dlg(): no dialog callid='74178fce-d298-0315-ecfe-5537f7dfb7c9' found
12(3162) DEBUG: ims_dialog [dlg_hash.c:1788]: search_dlg(): dialog with callid='74178fce-d298-0315-ecfe-5537f7dfb7c9' not found
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1615]: dlg_new_dialog(): Building new Dialog for call-id 74178fce-d298-0315-ecfe-5537f7dfb7c9
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1616]: dlg_new_dialog(): SIP Method: INVITE  
12(3162) DEBUG: ims_dialog [dlg_hash.c:342]: build_new_dlg(): new dialog on hash 3165
12(3162) DEBUG: ims_dialog [dlg_handlers.c:240]: populate_leg_info(): route_set <sip:mo at 192.168.99.140;lr=on;ftag=19054650;rm=8>, contact sip:alice at 192.168.99.145:60101;transport=udp, cseq 31553 and bind_addr udp:192.168.99.140:6060 [0xb6da4e88]
12(3162) DEBUG: ims_dialog [dlg_hash.c:1006]: link_dlg(): linking dialog [3165:2638]
12(3162) DEBUG: ims_dialog [dlg_hash.c:1015]: link_dlg(): ref dlg 0xb20619f4 with 1 -> 1
12(3162) DEBUG: ims_dialog [dlg_cb.c:237]: run_create_callbacks(): Running DLG_CREATED callbacks
12(3162) DEBUG: ims_dialog [dlg_cb.c:251]: run_create_callbacks(): dialog=0xb20619f4
12(3162) DEBUG: ims_dialog [dlg_handlers.c:512]: get_dlg_timeout(): invalid AVP value, using default timeout
12(3162) DEBUG: ims_dialog [dlg_profile.c:419]: set_current_dialog(): setting current dialog [3165:2638]
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1672]: dlg_new_dialog(): New dialog created
12(3162) DEBUG: ims_dialog [dlg_hash.c:879]: lookup_dlg(): ref dlg 0xb20619f4 with 1 -> 2
12(3162) DEBUG: ims_dialog [dlg_hash.c:881]: lookup_dlg(): dialog id=2638 found on entry 3165
12(3162) DEBUG: ims_dialog [dlg_handlers.c:784]: dlg_onreq(): dialog [0xb20619f4] added to tm callbacks
12(3162) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 1
12(3162) INFO: ims_isc [ims_isc_mod.c:233]: isc_match_filter(): Checking triggers
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1172]: dlg_onreply(): ONREPLY CALL_BACK from TM received and type is [256] = [TMCB_REQUEST_OUT]
12(3162) DEBUG: ims_dialog [dlg_hash.c:879]: lookup_dlg(): ref dlg 0xb20619f4 with 1 -> 2
12(3162) DEBUG: ims_dialog [dlg_hash.c:881]: lookup_dlg(): dialog id=2638 found on entry 3165
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1188]: dlg_onreply(): DLG dialogid is entry:id [3165:2638]
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1196]: dlg_onreply(): Received Request out for request [INVITE sip:bob at koffee-ims.in SIP/2.0
Record-Route: <sip:mo at 192.168.99.140:6060;lr=on;ftag=19054650;did=d5c.e4a>
Record-Route: <sip:mo at 192.168.99.140;lr=on;ftag=19054650;rm=8>
Via: SIP/2.0/UDP 192.168.99.140:6060;branch=z9hG4bKb26e.4f95ab7c27413f23c522be9aa43dd326.0
Via: SIP/2.0/UDP 192.168.99.140;branch=z9hG4bKb26e.5f4e6fb5bd7a2bc208cc932f7a828e2a.0
Via: SIP/2.0/UDP 192.168.99.145:60101;received=192.168.99.145;branch=z9hG4bK19067030;rport=60101
From: <sip:alice at koffee-ims.in>;tag=19054650
To: <sip:bob at koffee-ims.in>
Contact: <sip:alice at 192.168.99.145:60101;transport=udp>;+g.oma.sip-im;language="en,fr";+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel"
Call-ID: 74178fce-d298-0315-ecfe-5537f7dfb7c9
CSeq: 31553 INVITE
Content-Type: application/sdp
Content-Length: 531
Max-Forwards: 68
Accept-Contact: *;+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel"
P-Preferred-Service: urn:urn-7:3gpp-service.ims.icsi.mmtel
Allow: INVITE, ACK, CANCEL, BYE, MESSAGE, OPTIONS, NOTIFY, PRACK, UPDATE, REFER
Privacy: none
P-Access-Network-Info: ADSL;utran-cell-id-3gpp=00000000
User-Agent: IM-client/OMA1.0 Boghe-Win32/v2.0.153.836
Supported: 100rel
P-Charging-Vector: icid-value=4956537F000101980B0000D401000000; icid-generated-at=192.168.99.140
P-Visited-Network-ID: koffee-ims.in
P-Asserted-Identity: <sip:alice at koffee-ims.in>

v=0
o=doubango 1983 678901 IN IP4 192.168.99.140
s=-
c=IN IP4 192.168.99.140
t=0 0
a=tcap:1 RTP/AVPF
m=audio 30000 RTP/AVP 0 3 8 97 101
a=ptime:20
a=silenceSupp:off - - - -
a=rtpmap:0 PCMU/8000/1
a=rtpmap:3 GSM/8000/1
a=rtpmap:8 PCMA/8000/1
a=rtpmap:97 SPEEX/8000/1
a=rtpmap:101 telephone-event/8000/1
a=fmtp:101 0-16
a=pcfg:1 t=1
a=ssrc:1056905624 cname:ldjWoB60jbyQlR6e
a=ssrc:1056905624 mslabel:6994f7d1-6ce9-4fbd-acfd-84e5131ca2e2
a=ssrc:1056905624 label:Doubango.Audio
a=sendrecv
a=rtcp:30001
a=rtcp-mux
]
12(3162) DEBUG: ims_dialog [dlg_handlers.c:1202]: dlg_onreply(): Ignoring request out as it's not a CANCEL
12(3162) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 1
12(3162) ERROR: <script>: No=3 Inside checking sip:After route
 3(3149) DEBUG: ims_dialog [dlg_handlers.c:1172]: dlg_onreply(): ONREPLY CALL_BACK from TM received and type is [2] = [TMCB_RESPONSE_IN]
 3(3149) DEBUG: ims_dialog [dlg_hash.c:879]: lookup_dlg(): ref dlg 0xb20619f4 with 1 -> 2
 3(3149) DEBUG: ims_dialog [dlg_hash.c:881]: lookup_dlg(): dialog id=2638 found on entry 3165
 3(3149) DEBUG: ims_dialog [dlg_handlers.c:1188]: dlg_onreply(): DLG dialogid is entry:id [3165:2638]
 3(3149) DEBUG: ims_dialog [dlg_profile.c:419]: set_current_dialog(): setting current dialog [3165:2638]
 3(3149) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 1
 8(3158) DEBUG: ims_dialog [dlg_handlers.c:1172]: dlg_onreply(): ONREPLY CALL_BACK from TM received and type is [2] = [TMCB_RESPONSE_IN]
 8(3158) DEBUG: ims_dialog [dlg_hash.c:879]: lookup_dlg(): ref dlg 0xb20619f4 with 1 -> 2
 8(3158) DEBUG: ims_dialog [dlg_hash.c:881]: lookup_dlg(): dialog id=2638 found on entry 3165
 8(3158) DEBUG: ims_dialog [dlg_handlers.c:1188]: dlg_onreply(): DLG dialogid is entry:id [3165:2638]
 8(3158) DEBUG: ims_dialog [dlg_profile.c:419]: set_current_dialog(): setting current dialog [3165:2638]
 8(3158) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 1
 1(3147) ERROR: <script>: Inside route{........}
 1(3147) ERROR: <script>: No=1 Before checking sip:orig at .*
 1(3147) DEBUG: ims_dialog [dlg_profile.c:596]: is_dlg_in_profile(): Getting current dialog 1(3147) DEBUG: ims_dialog [dlg_hash.h:414]: match_dialog(): No dlg outs yet...
 1(3147) DEBUG: ims_dialog [dlg_hash.c:915]: internal_get_dlg(): ref dlg 0xb20619f4 with 1 -> 2
 1(3147) DEBUG: ims_dialog [dlg_hash.c:918]: internal_get_dlg(): dialog callid='74178fce-d298-0315-ecfe-5537f7dfb7c9' found on entry 3165, dir=1
 1(3147) DEBUG: ims_dialog [dlg_profile.c:605]: is_dlg_in_profile(): Current dlg found 1(3147) DEBUG: ims_dialog [dlg_profile.c:612]: is_dlg_in_profile(): Running through linkers 1(3147) DEBUG: ims_dialog [dlg_profile.c:614]: is_dlg_in_profile(): Profile matches 1(3147) DEBUG: ims_dialog [dlg_profile.c:616]: is_dlg_in_profile(): Profile has value is zero returning true 1(3147) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 1
 1(3147) DEBUG: ims_dialog [dlg_profile.c:596]: is_dlg_in_profile(): Getting current dialog 1(3147) DEBUG: ims_dialog [dlg_hash.h:414]: match_dialog(): No dlg outs yet...
 1(3147) DEBUG: ims_dialog [dlg_hash.c:915]: internal_get_dlg(): ref dlg 0xb20619f4 with 1 -> 2
 1(3147) DEBUG: ims_dialog [dlg_hash.c:918]: internal_get_dlg(): dialog callid='74178fce-d298-0315-ecfe-5537f7dfb7c9' found on entry 3165, dir=1
 1(3147) DEBUG: ims_dialog [dlg_profile.c:605]: is_dlg_in_profile(): Current dlg found 1(3147) DEBUG: ims_dialog [dlg_profile.c:612]: is_dlg_in_profile(): Running through linkers 1(3147) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 1
 1(3147) ERROR: <script>: No=9 Terminating ---403  Forbidden - Domain not served 
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1172]: dlg_onreply(): ONREPLY CALL_BACK from TM received and type is [2] = [TMCB_RESPONSE_IN]
 6(3153) DEBUG: ims_dialog [dlg_hash.c:879]: lookup_dlg(): ref dlg 0xb20619f4 with 1 -> 2
 6(3153) DEBUG: ims_dialog [dlg_hash.c:881]: lookup_dlg(): dialog id=2638 found on entry 3165
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1188]: dlg_onreply(): DLG dialogid is entry:id [3165:2638]
 6(3153) DEBUG: ims_dialog [dlg_profile.c:419]: set_current_dialog(): setting current dialog [3165:2638]
 6(3153) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 1
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1172]: dlg_onreply(): ONREPLY CALL_BACK from TM received and type is [128] = [TMCB_ON_FAILURE]
 6(3153) DEBUG: ims_dialog [dlg_hash.c:879]: lookup_dlg(): ref dlg 0xb20619f4 with 1 -> 2
 6(3153) DEBUG: ims_dialog [dlg_hash.c:881]: lookup_dlg(): dialog id=2638 found on entry 3165
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1188]: dlg_onreply(): DLG dialogid is entry:id [3165:2638]
 6(3153) DEBUG: ims_dialog [dlg_profile.c:419]: set_current_dialog(): setting current dialog [3165:2638]
 6(3153) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 1
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1172]: dlg_onreply(): ONREPLY CALL_BACK from TM received and type is [1048576] = [TMCB_RESPONSE_READY]
 6(3153) DEBUG: ims_dialog [dlg_hash.c:879]: lookup_dlg(): ref dlg 0xb20619f4 with 1 -> 2
 6(3153) DEBUG: ims_dialog [dlg_hash.c:881]: lookup_dlg(): dialog id=2638 found on entry 3165
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1188]: dlg_onreply(): DLG dialogid is entry:id [3165:2638]
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1230]: dlg_onreply(): Extracting to-tag from reply 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1250]: dlg_onreply(): Got to-tag from response: 84772552fab76e8916cf9e5dd5027417.9b14 
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1270]: dlg_onreply(): Calling next_state_dlg and event is 4 = DLG_EVENT_RPL3xx
 6(3153) DEBUG: ims_dialog [dlg_hash.c:1283]: next_state_dlg(): dialog 0xb20619f4 changed from state 1 to state 6, due event 4
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1274]: dlg_onreply(): Checking if there is an existing dialog_out entry with same to-tag 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1295]: dlg_onreply(): Extracting to-tag from reply 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1326]: dlg_onreply(): Got to-tag from response: 84772552fab76e8916cf9e5dd5027417.9b14 
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1333]: dlg_onreply(): Scanning dlg_entry_out list for dlg_out 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1404]: dlg_onreply(): new state is 6 and old state is 1
 6(3153) DEBUG: ims_dialog [dlg_handlers.c:1484]: dlg_onreply(): dialog 0xb20619f4 failed (negative reply)
 6(3153) DEBUG: ims_dialog [dlg_cb.c:277]: run_dlg_callbacks(): dialog=0xb20619f4, type=4
 6(3153) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 1
 6(3153) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): unref dlg 0xb20619f4 with 1 -> 0
 6(3153) DEBUG: ims_dialog [dlg_hash.c:1056]: unref_dlg(): ref <=0 for dialog 0xb20619f4
 6(3153) DEBUG: ims_dialog [dlg_hash.c:194]: destroy_dlg(): destroying dialog 0xb20619f4
 6(3153) DEBUG: ims_dialog [dlg_hash.c:209]: destroy_dlg(): removed timer for dlg 0xb20619f4 [3165:2638] with clid '74178fce-d298-0315-ecfe-5537f7dfb7c9' and tags '19054650' 
 6(3153) DEBUG: ims_dialog [dlg_hash.c:216]: destroy_dlg(): About to run dlg callback for destroy
 6(3153) DEBUG: ims_dialog [dlg_cb.c:277]: run_dlg_callbacks(): dialog=0xb20619f4, type=8192
 6(3153) DEBUG: ims_dialog [dlg_hash.c:218]: destroy_dlg(): DONE: About to run dlg callback for destroy
 6(3153) DEBUG: ims_dialog [dlg_hash.c:154]: destroy_entry_out(): Destroy dialog entry out
 2(3148) ERROR: <script>: Inside route{........}
 2(3148) WARNING: tm [t_lookup.c:1465]: t_unref(): script writer didn't release transaction
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64087037
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64087037
14(3164) DEBUG: ims_dialog [dlg_handlers.c:284]: dlg_iuid_sfree(): freeing dlg iuid [3165:2638] (0xb2061e1c)
11(3161) ERROR: <script>: Inside route{........}
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64087047
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64087047
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1918]: print_all_dlgs(): ********************13(3163) DEBUG: ims_dialog [dlg_handlers.c:1919]: print_all_dlgs(): printing 4096 dialogs
13(3163) DEBUG: ims_dialog [dlg_handlers.c:1929]: print_all_dlgs(): ********************13(3163) DEBUG: ims_auth [authorize.c:193]: reg_await_timer(): Looking for expired/useless at 64087057
13(3163) DEBUG: ims_auth [authorize.c:238]: reg_await_timer(): [DONE] Looking for expired/useless at 64087057
10(3160) ERROR: <script>: Inside route{........}




More information about the sr-dev mailing list