Thanks for your replies too Matt and Dale,
I have put the sipstatus log into debug mode and re-sent a
voicemail to the account - debug attached (I have tried to
filter out event before and after test, in addition I have
removed some site specific info and substituted with generic
terms e.g. MyServer, MyDomain, IP: 161.X.XXX.XX.
The MWI is being sent to user account 53082, you may see
this being sent to 1153082 as well, this is because the
phone is connected to an external system and the 11 is
stripped off by the gateway - I also have this configured on
the test system which works without issue.
Thanks again!
Abdul
PS - I also have the server configured to sent email
notifications, which is working without issue - in other
words the DNS function must be working for other features.
"2010-07-28T14:18:15.970584Z":122:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:18:23.969409Z":123:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:18:31.969337Z":124:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:18:39.969247Z":125:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:18:47.969253Z":126:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:18:50.360296Z":127:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSLServerSocket::accept
socket accepted: 11"
"2010-07-28T14:18:50.362819Z":128:KERNEL:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSL::_
0x95bee08 CTX 0x95c8840 loaded key pair:\n public
'/etc/sipxpbx/ssl/ssl.crt'\n private '/etc/sipxpbx/ssl/ssl.key'"
"2010-07-28T14:18:50.362950Z":129:KERNEL:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsConnectionSocket::_[2]
((null), 11)"
"2010-07-28T14:18:50.362989Z":130:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSLConnectionSocket::_(SSL
0x95c9540, socket 11)"
"2010-07-28T14:18:50.379261Z":131:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSLServerSocket::accept
SSL Connection:\n status: Verified\n peer:
'/C=US/ST=AnyState/L=AnyTown/O=MyDomain.com/OU=sipXecs/CN=MyServere.MyDomain.com/emailaddress=r...@myservere.mydomain.com'\n
alt names: sip:MyDomain.com,MyServere.MyDomain.com\n cipher: 'RC4-MD5'\n
issuer:
'/C=US/ST=AnyState/L=AnyTown/O=MyDomain.com/OU=sipXecs/CN=ca.MyServere.MyDomain.com/emailaddress=r...@myservere.mydomain.com'"
"2010-07-28T14:18:50.379330Z":132:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSLServerSocket::accept
connection 0x95accf0"
"2010-07-28T14:18:50.379457Z":133:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSL::peerIdentity
verified
'/C=US/ST=AnyState/L=AnyTown/O=MyDomain.com/OU=sipXecs/CN=MyServere.MyDomain.com/emailaddress=r...@myservere.mydomain.com'
'sip:MyDomain.com' 'MyServere.MyDomain.com'"
"2010-07-28T14:18:50.379500Z":134:SIP:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSLConnectionSocket::peerIdentity
0x95caf78 OsSSL returned trusted"
"2010-07-28T14:18:50.380209Z":135:HTTP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"HttpMessage::read
full msg rcvd bytes 463: header: 298 content: 165"
"2010-07-28T14:18:50.380382Z":136:SIP:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"HttpServer::processRequest
POST '/cgi/StatusEvent.cgi'"
"2010-07-28T14:18:50.380439Z":137:SIP:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"HttpServer::mapUri
mapped '/cgi/StatusEvent.cgi' -> '/cgi/StatusEvent.cgi'"
"2010-07-28T14:18:50.380488Z":138:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"HttpRequestContext::_(
connection=0x95caf78 ) Cert Trusted"
"2010-07-28T14:18:50.380615Z":139:SIP:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"WebServer::ProcessEvent
HttpEvent \nPOST /cgi/StatusEvent.cgi HTTP/1.1\r\nContent-Type:
application/simple-message-summary\r\nCache-Control: no-cache\r\nPragma:
no-cache\r\nUser-Agent: Java/1.6.0_03\r\nHost:
MyServere.MyDomain.com:8101\r\nAccept: text/html, image/gif, image/jpeg, *;
q=.2, */*; q=.2\r\nConnection: keep-alive\r\nContent-Length:
165\r\n\r\neventType=message-summary&identity=53082%40MyServere.MyDomain.com\r\nMessages-Waiting:
yes\r\nMessage-Account: sip:53...@myservere.mydomain.com\r\nvoice-message: 2/0
(0/0)"
"2010-07-28T14:18:50.380689Z":140:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"MwiPlugin::handleEvent
notice for '53...@myservere.mydomain.com\r\nmessages-waiting:
yes\r\nMessage-Account: sip:53...@myservere.mydomain.com\r\nvoice-message: 2/0
(0/0)'"
"2010-07-28T14:18:50.380818Z":141:SIP:ERR:MyServer:HttpServer-2:B6D78B90:SipStatus:"Url::parseString
error - expected end of url or field parameter ';name=' at offset 26 in
'53...@myservere.mydomain.com\r\nmessages-waiting: yes\r\nMessage-Account:
sip:53...@myservere.mydomain.com\r\nvoice-message: 2/0 (0/0)'"
"2010-07-28T14:18:50.381314Z":142:SUPERVISOR:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"UserStaticDB::_
users = 2, mTableLoaded = 1"
"2010-07-28T14:18:50.381475Z":143:SUPERVISOR:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"UserStaticDB::_
rows in table = 1"
"2010-07-28T14:18:50.381557Z":144:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"Notifier::sendNotifyForeachSubscription
configured contact 53...@myservere.mydomain.com"
"2010-07-28T14:18:50.382297Z":145:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"BranchId::equals(UtlString
'')\n 'z9hG4bK-XX-00002UvXcbLVMSop8gkEa4xEZw'"
"2010-07-28T14:18:50.382783Z":146:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"SipSrvLookup::servers
domain = 'MyServere.MyDomain.com', service = 'sip', socketType = UNKNOWN, port
= -1"
"2010-07-28T14:18:50.382862Z":147:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTask::_
'SipSrvLookupThread-14' created 0x95cc718"
"2010-07-28T14:18:50.382916Z":148:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsServerTask::_
'SipSrvLookupThread-14' queue: 0x95cc85c queue limit: 100"
"2010-07-28T14:18:50.383017Z":149:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTaskLinux::start
'SipSrvLookupThread-14' this = 0x95cc718, mTaskId = -1231598704"
"2010-07-28T14:18:50.383073Z":150:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTask::_
'SipSrvLookupThread-15' created 0x95ccc00"
"2010-07-28T14:18:50.383125Z":151:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsServerTask::_
'SipSrvLookupThread-15' queue: 0x95ccd44 queue limit: 100"
"2010-07-28T14:18:50.383192Z":152:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTaskLinux::start
'SipSrvLookupThread-15' this = 0x95ccc00, mTaskId = -1232651376"
"2010-07-28T14:18:50.383239Z":153:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTask::_
'SipSrvLookupThread-16' created 0x95cd180"
"2010-07-28T14:18:50.383290Z":154:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsServerTask::_
'SipSrvLookupThread-16' queue: 0x95cd2c4 queue limit: 100"
"2010-07-28T14:18:50.383465Z":155:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTaskLinux::start
'SipSrvLookupThread-16' this = 0x95cd180, mTaskId = -1233704048"
"2010-07-28T14:18:50.383521Z":156:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTask::_
'SipSrvLookupThread-17' created 0x95cd700"
"2010-07-28T14:18:50.383556Z":157:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsServerTask::_
'SipSrvLookupThread-17' queue: 0x95cd844 queue limit: 100"
"2010-07-28T14:18:50.383632Z":158:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTaskLinux::start
'SipSrvLookupThread-17' this = 0x95cd700, mTaskId = -1234756720"
"2010-07-28T14:18:50.383763Z":159:SIP:DEBUG:MyServer:SipSrvLookupThread-14:B6974B90:SipStatus:"SipSrvLookup::res_query_and_parse
in_name = '_sip._udp.MyServere.MyDomain.com', type = 33 (SRV)"
"2010-07-28T14:18:50.383919Z":160:SIP:DEBUG:MyServer:SipSrvLookupThread-16:B6772B90:SipStatus:"SipSrvLookup::res_query_and_parse
in_name = '_sip._tls.MyServere.MyDomain.com', type = 33 (SRV)"
"2010-07-28T14:18:50.384173Z":161:SIP:DEBUG:MyServer:SipSrvLookupThread-15:B6873B90:SipStatus:"SipSrvLookup::res_query_and_parse
in_name = '_sip._tcp.MyServere.MyDomain.com', type = 33 (SRV)"
"2010-07-28T14:18:50.384297Z":162:SIP:DEBUG:MyServer:SipSrvLookupThread-17:B6671B90:SipStatus:"SipSrvLookup::res_query_and_parse
in_name = 'MyServere.MyDomain.com', type = 1 (A)"
"2010-07-28T14:18:50.384672Z":163:SIP:WARNING:MyServer:SipSrvLookupThread-16:B6772B90:SipStatus:"DNS
query for name '_sip._tls.MyServere.MyDomain.com', type = 33 (SRV): returned
error"
"2010-07-28T14:18:50.384751Z":164:SIP:DEBUG:MyServer:SipSrvLookupThread-16:B6772B90:SipStatus:"SipSrvLookup::res_query_and_parse
out_name = '_sip._tls.MyServere.MyDomain.com', out_response = (nil)"
"2010-07-28T14:18:50.384764Z":165:SIP:WARNING:MyServer:SipSrvLookupThread-15:B6873B90:SipStatus:"DNS
query for name '_sip._tcp.MyServere.MyDomain.com', type = 33 (SRV): returned
error"
"2010-07-28T14:18:50.384804Z":166:SIP:WARNING:MyServer:SipSrvLookupThread-14:B6974B90:SipStatus:"DNS
query for name '_sip._udp.MyServere.MyDomain.com', type = 33 (SRV): returned
error"
"2010-07-28T14:18:50.384838Z":167:SIP:DEBUG:MyServer:SipSrvLookupThread-15:B6873B90:SipStatus:"SipSrvLookup::res_query_and_parse
out_name = '_sip._tcp.MyServere.MyDomain.com', out_response = (nil)"
"2010-07-28T14:18:50.384846Z":168:SIP:DEBUG:MyServer:SipSrvLookupThread-14:B6974B90:SipStatus:"SipSrvLookup::res_query_and_parse
out_name = '_sip._udp.MyServere.MyDomain.com', out_response = (nil)"
"2010-07-28T14:18:50.385124Z":169:SIP:DEBUG:MyServer:SipSrvLookupThread-17:B6671B90:SipStatus:"SipSrvLookup::res_query_and_parse
out_name = 'MyServere.MyDomain.com', out_response = 0x95cdc90"
"2010-07-28T14:18:50.385271Z":170:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"SipSrvLookup::servers
host = 'MyServere.MyDomain.com', IP addr = '161.X.XXX.XX', port = 5060, weight
= 0, score = 1000.000000, priority = 0, proto = UDP"
"2010-07-28T14:18:50.385322Z":171:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"SipSrvLookup::servers
host = 'MyServere.MyDomain.com', IP addr = '161.X.XXX.XX', port = 5060, weight
= 0, score = 1000.000000, priority = 0, proto = TCP"
"2010-07-28T14:18:50.385490Z":172:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"SipTransaction::recurseDnsSrvChildren
transaction 0x95cb250 setting timeout 8 secs."
"2010-07-28T14:18:50.386066Z":173:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTask::_
'SipClientUdp-18' created 0xb6403c80"
"2010-07-28T14:18:50.386125Z":174:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsServerTask::_
'SipClientUdp-18' queue: 0xb6403dc4 queue limit: 100"
"2010-07-28T14:18:50.386182Z":175:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsServerTaskWaitable::_
pipe() opened 13 -> 12"
"2010-07-28T14:18:50.386414Z":176:SIP:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"SipClient[SipClientUdp-18]::_
created UDP shared socket 7: host '' '' port 0, local IP '161.X.XXX.XX' port
5110"
"2010-07-28T14:18:50.386624Z":177:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsTaskLinux::start
'SipClientUdp-18' this = 0xb6403c80, mTaskId = -1237320816"
"2010-07-28T14:18:50.386705Z":178:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"SipProtocolServerBase[SipUdpServer-7]::getClientForDestination
client: SipClientUdp-18(0xb6403c80) '161.X.XXX.XX':5060 local '161.X.XXX.XX'"
"2010-07-28T14:18:50.386785Z":179:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"SipProtocolServerBase[SipUdpServer-7]::send
SipClientUdp-18 (0xb6403c80), remote host: :0 remote IP: :0 remote Via
address: :-1 received address: :-1"
"2010-07-28T14:18:50.387093Z":180:OUTGOING:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"SipUserAgent::sendUdp
UDP SIP User Agent sent message:\n----Local Host:161.X.XXX.XX---- Port:
5110----\n----Remote Host:161.X.XXX.XX---- Port: 5060----\nNOTIFY
sip:1153...@myservere.mydomain.com SIP/2.0\r\nContent-Type:
application/simple-message-summary\r\nContent-Length: 100\r\nEvent:
message-summary\r\nSubscription-State: terminated\r\nFrom:
sip:i...@myservere.mydomain.com\r\nto:
sip:53...@myservere.mydomain.com\r\ncall-id:
static-mwi-53...@myservere.mydomain.com-0000\r\ncseq: 0 NOTIFY\r\nContact:
53...@myservere.mydomain.com\r\nuser-agent: sipXecs/4.2.1 sipXecs/publisher
(Linux)\r\nDate: Wed, 28 Jul 2010 14:18:50 GMT\r\nMax-Forwards:
20\r\nAccept-Language: en\r\nSupported: sip-cc-01, timer\r\nVia: SIP/2.0/UDP
161.X.XXX.XX:5110;branch=z9hG4bK-XX-0001U`7SkJ4TxkrC`X3xn2tcrQ\r\n\r\nMessages-Waiting:
yes\r\nMessage-Account: sip:53...@myservere.mydomain.com\r\nvoice-message: 2/0
(0/0)\r\n\r\n--------------------END--------------------"
"2010-07-28T14:18:50.387302Z":181:SIP:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"SipTransaction::doFirstSend
transaction 0xb6400d48 setting timeout 4 secs."
"2010-07-28T14:18:50.387403Z":182:SIP:DEBUG:MyServer:SipClientUdp-18:B63FFB90:SipStatus:"SipClient[SipClientUdp-18]::run
start tcpOnErrWaitForSend-1 waitingToReportErr-0 mbTcpOnErrWaitForSend-1
repeatedEOFs-0"
"2010-07-28T14:18:50.387441Z":183:SIP:DEBUG:MyServer:SipClientUdp-18:B63FFB90:SipStatus:"SipClient[SipClientUdp-18]::run
resPoll= 1 revents: fd[0]= 1 fd[1]= 0"
"2010-07-28T14:18:50.387467Z":184:SIP:DEBUG:MyServer:SipClientUdp-18:B63FFB90:SipStatus:"SipClient[SipClientUdp-18]::run
got pipe-select Number of Messages waiting: 1"
"2010-07-28T14:18:50.387541Z":185:SIP:DEBUG:MyServer:SipClientUdp-18:B63FFB90:SipStatus:"SipClient[SipClientUdp-18]::run
got pipe-select mbTcpOnErrWaitForSend-0 waitingToReportErr-0
mbTcpOnErrWaitForSend-0 repeatedEOFs-0"
"2010-07-28T14:18:50.387731Z":186:SIP:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"Notifier::sendNotifyForeachSubscription:
no 'message-summary' subscriptions for '53...@myservere.mydomain.com'"
"2010-07-28T14:18:50.387990Z":187:KERNEL:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSLConnectionSocket::close"
"2010-07-28T14:18:50.388205Z":188:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSLConnectionSocket::~"
"2010-07-28T14:18:50.388252Z":189:KERNEL:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSSLConnectionSocket::close"
"2010-07-28T14:18:50.388298Z":190:KERNEL:INFO:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsConnectionSocket::~"
"2010-07-28T14:18:50.388476Z":191:KERNEL:DEBUG:MyServer:HttpServer-2:B6D78B90:SipStatus:"OsSocket::~
close socket 11"
"2010-07-28T14:18:50.404950Z":192:SIP:DEBUG:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"SipClient[SipClientUdp-9]::run
resPoll= 1 revents: fd[0]= 0 fd[1]= 1"
"2010-07-28T14:18:50.405223Z":193:INCOMING:INFO:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"Read
SIP message:\n----Local Host:161.X.XXX.XX---- Port: 5110----\n----Remote
Host:161.X.XXX.XX---- Port: 5060----\nSIP/2.0 403 Forbidden\r\nDate: Wed, 28
Jul 2010 14:18:50 GMT\r\nFrom:
sip:i...@myservere.mydomain.com\r\ncontent-length: 0\r\nTo:
sip:53...@myservere.mydomain.com;tag=50876097\r\nCall-Id:
static-mwi-53...@myservere.mydomain.com-0000\r\ncseq: 0 NOTIFY\r\nVia:
SIP/2.0/UDP
161.X.XXX.XX:5110;branch=z9hG4bK-XX-0001U`7SkJ4TxkrC`X3xn2tcrQ\r\n\r\n====================END===================="
"2010-07-28T14:18:50.405561Z":194:SIP:DEBUG:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"BranchId::equals(UtlString
'z9hG4bK-XX-0001U`7SkJ4TxkrC`X3xn2tcrQ')\n
'z9hG4bK-XX-0001U`7SkJ4TxkrC`X3xn2tcrQ'"
"2010-07-28T14:18:50.405632Z":195:SIP:DEBUG:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"SipUserAgent[SipUserAgent-3]::dispatch
transaction = 0xb6400d48, relationship = 6"
"2010-07-28T14:18:50.405674Z":196:SIP:DEBUG:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"SipTransaction::handleIncoming
0xb6400d48 relationship FINAL"
"2010-07-28T14:18:50.405732Z":197:SIP:DEBUG:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"SipTransaction::handleChildIncoming
0xb6400d48 relationship FINAL parent 0x95cb250"
"2010-07-28T14:18:50.405765Z":198:SIP:DEBUG:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"SipTransaction::handleChildIncoming
0x95cb250 relationship FINAL parent (nil)"
"2010-07-28T14:18:50.405799Z":199:SIP:DEBUG:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"SipTransaction::handleChildIncoming
0x95cb250"
"2010-07-28T14:18:50.405871Z":200:SIP:DEBUG:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"SipTransaction::findBestChildResponse
0x95cb250 child 0xb6400d48 status/pri 403/3 (bestResp 0/8) usethis=1 pathNum 1"
"2010-07-28T14:18:50.405965Z":201:SIP:DEBUG:MyServer:SipClientUdp-9:B78FCB90:SipStatus:"SipTransaction::handleChildIncoming
response 403 for Call-Id 'static-mwi-53...@myservere.mydomain.com-0000'"
"2010-07-28T14:18:50.406318Z":202:SIP:DEBUG:MyServer:StatusServer:B6A75B90:SipStatus:"StatusServer::handleMessage()
:: Start processing SIP message"
"2010-07-28T14:18:50.406594Z":203:SIP:WARNING:MyServer:SubscribeServerThread:B6B76B90:SipStatus:"SubscribeServerThread::removeErrorSubscription
static-mwi-53...@myservere.mydomain.com-0000"
"2010-07-28T14:18:50.406737Z":204:SIPDB:DEBUG:MyServer:SubscribeServerThread:B6B76B90:SipStatus:"SubscriptionDB::removeErrorRow
row not found:\nto='sip:i...@myservere.mydomain.com'
from='sip:53...@myservere.mydomain.com;tag=50876097'
callid='static-mwi-53...@myservere.mydomain.com-0000'"
"2010-07-28T14:18:50.406795Z":205:SIP:DEBUG:MyServer:SubscribeServerThread:B6B76B90:SipStatus:"SubscribePersistThread::schedulePersist
in 20 seconds"
"2010-07-28T14:18:50.489510Z":206:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
resend Timeout of message for protocol 1, callId:
\"static-mwi-53...@myservere.mydomain.com-0000\""
"2010-07-28T14:18:50.489657Z":207:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"BranchId::equals(UtlString
'z9hG4bK-XX-0001U`7SkJ4TxkrC`X3xn2tcrQ')\n
'z9hG4bK-XX-0001U`7SkJ4TxkrC`X3xn2tcrQ'"
"2010-07-28T14:18:50.489727Z":208:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipTransaction::handleResendEvent
no response, TRANSACTION_COMPLETE"
"2010-07-28T14:18:50.489797Z":209:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipTransaction::findBestChildResponse
0x95cb250 child 0xb6400d48 status/pri 403/3 (bestResp 0/8) usethis=1 pathNum 1"
"2010-07-28T14:18:50.489981Z":210:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:18:54.388937Z":211:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
transaction expiration message received"
"2010-07-28T14:18:54.389078Z":212:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"BranchId::equals(UtlString
'z9hG4bK-XX-0001U`7SkJ4TxkrC`X3xn2tcrQ')\n
'z9hG4bK-XX-0001U`7SkJ4TxkrC`X3xn2tcrQ'"
"2010-07-28T14:18:54.389152Z":213:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipTransaction::handleExpiresEvent
0xb6400d48 ignoring timeout cancel of DNS SRV child"
"2010-07-28T14:18:54.389229Z":214:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipTransaction::findBestChildResponse
0x95cb250 child 0xb6400d48 status/pri 403/3 (bestResp 0/8) usethis=1 pathNum 1"
"2010-07-28T14:18:54.389410Z":215:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:18:55.969119Z":216:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:18:58.387391Z":217:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
transaction expiration message received"
"2010-07-28T14:18:58.387535Z":218:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"BranchId::equals(UtlString
'z9hG4bK-XX-00002UvXcbLVMSop8gkEa4xEZw')\n
'z9hG4bK-XX-00002UvXcbLVMSop8gkEa4xEZw'"
"2010-07-28T14:18:58.387637Z":219:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipTransaction::findBestChildResponse
0x95cb250 child 0xb6400d48 status/pri 403/3 (bestResp 0/8) usethis=1 pathNum 1"
"2010-07-28T14:18:58.387821Z":220:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:19:03.969045Z":221:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:19:10.409233Z":222:SIP:DEBUG:MyServer:SubscribePersistThread:B6C77B90:SipStatus:"SubscribePersistThread::handleMessage
received message 3/1"
"2010-07-28T14:19:10.409340Z":223:KERNEL:DEBUG:MyServer:SubscribePersistThread:B6C77B90:SipStatus:"SipXecsService::Path('SIPX_DBDIR',
'subscription.xml') returning '/var/sipxdata/sipdb/subscription.xml'"
"2010-07-28T14:19:11.967961Z":224:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:19:11.968051Z":225:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipProtocolServerBase[SipUdpServer-7]::removeOldClients
Removing old client SipClientUdp-18(0xb6403c80): remote host: :0 remote IP:
:0 remote Via address: :-1 received address: :-1"
"2010-07-28T14:19:11.968098Z":226:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipProtocolServerBase[SipUdpServer-7]::removeOldClients
deleting 1 of 1 SipClients"
"2010-07-28T14:19:11.968132Z":227:KERNEL:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"OsTaskLinux::waitUntilShutDown
'SipUserAgent-3' for 'SipClientUdp-18' RUNNING"
"2010-07-28T14:19:11.968171Z":228:KERNEL:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"OsTaskBase::requestShutdown
on task 'SipClientUdp-18', transition RUNNING -> SHUTTING_DOWN"
"2010-07-28T14:19:11.968274Z":229:SIP:DEBUG:MyServer:SipClientUdp-18:FFFFFFFF:SipStatus:"SipClient[SipClientUdp-18]::run
resPoll= 1 revents: fd[0]= 1 fd[1]= 0"
"2010-07-28T14:19:11.968317Z":230:SIP:DEBUG:MyServer:SipClientUdp-18:FFFFFFFF:SipStatus:"SipClient[SipClientUdp-18]::run
got pipe-select Number of Messages waiting: 1"
"2010-07-28T14:19:11.968378Z":231:SIP:DEBUG:MyServer:SipClientUdp-18:FFFFFFFF:SipStatus:"SipClient[SipClientUdp-18]::run
got pipe-select mbTcpOnErrWaitForSend-0 waitingToReportErr-0
mbTcpOnErrWaitForSend-0 repeatedEOFs-0"
"2010-07-28T14:19:11.968430Z":232:KERNEL:DEBUG:MyServer:SipClientUdp-18:FFFFFFFF:SipStatus:"OsTaskBase::requestShutdown
on task 'SipClientUdp-18', transition SHUTTING_DOWN -> SHUTTING_DOWN"
"2010-07-28T14:19:11.968462Z":233:KERNEL:DEBUG:MyServer:SipClientUdp-18:FFFFFFFF:SipStatus:"OsServerTask::handleMessage:
OS_SHUTDOWN processed"
"2010-07-28T14:19:11.968511Z":234:KERNEL:DEBUG:MyServer:SipClientUdp-18:FFFFFFFF:SipStatus:"OsTaskLinux::ackShutdown
'SipClientUdp-18' SHUTTING_DOWN"
"2010-07-28T14:19:11.968545Z":235:KERNEL:DEBUG:MyServer:SipClientUdp-18:FFFFFFFF:SipStatus:"OsTaskLinux::ackShutdown
'SipClientUdp-18' shut down"
"2010-07-28T14:19:11.968608Z":236:KERNEL:DEBUG:MyServer:pid-6736:B63FFB90:SipStatus:"OsTaskLinux::ackShutdown
unregistered 'SipClientUdp-18'"
"2010-07-28T14:19:11.968890Z":237:KERNEL:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"OsTaskLinux::waitUntilShutDown
task 'SipUserAgent-3' done waiting for 'SipClientUdp-18'"
"2010-07-28T14:19:11.968921Z":238:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipClient[SipClientUdp-18]::~
called"
"2010-07-28T14:19:11.968975Z":239:KERNEL:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"OsServerTaskWaitable::~
closed 13 -> 12"
"2010-07-28T14:19:11.969001Z":240:KERNEL:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"OsServerTask::~
'SipClientUdp-18' TERMINATED"
"2010-07-28T14:19:11.969032Z":241:KERNEL:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"OsTaskLinux::waitUntilShutDown
'SipUserAgent-3' for 'SipClientUdp-18' TERMINATED"
"2010-07-28T14:19:11.969057Z":242:KERNEL:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"OsTaskLinux::waitUntilShutDown
task 'SipClientUdp-18' already shut down"
"2010-07-28T14:19:11.969112Z":243:KERNEL:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"OsTaskLinux::waitUntilShutDown
'SipUserAgent-3' for 'SipClientUdp-18' TERMINATED"
"2010-07-28T14:19:11.969137Z":244:KERNEL:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"OsTaskLinux::waitUntilShutDown
task 'SipClientUdp-18' already shut down"
"2010-07-28T14:19:19.968908Z":245:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:19:27.968831Z":246:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:19:27.968927Z":247:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipTransactionList::removeOldTransactions
deleting 3 of 3 transactions (0 busy)"
"2010-07-28T14:19:35.969769Z":248:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:19:43.969676Z":249:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
"2010-07-28T14:19:51.969597Z":250:SIP:DEBUG:MyServer:SipUserAgent-3:B76FAB90:SipStatus:"SipUserAgent[SipUserAgent-3]::handleMessage
calling garbageCollection()"
_______________________________________________
sipx-users mailing list
sipx-users@list.sipfoundry.org
List Archive: http://list.sipfoundry.org/archive/sipx-users/
