moved v9 to 2008 server - now has errors on prev wkng config

Discussion in '3CX Phone System - General' started by dbergsma, Apr 2, 2012.

Thread Status:
Not open for further replies.
  1. dbergsma

    Joined:
    Oct 27, 2008
    Messages:
    39
    Likes Received:
    0
    Hi folks,
    been on 3cx since v7. currently on v9.
    bought new 2008 server (to put 3cx on). moved v9 to 2008 server. receive internal errors (See description below).
    patched 2008 server to current, upgraded to 3cxv10, receive same errors.

    Windows firewall is turned off. Outside can dial in.
    installed desktop experience. digital receptionist works.

    dialing to extension sometimes fails. (ie: 60% of the time it fails).
    however, the rub: it is intermittent. a few calls work, then a few do not, then again, they do.
    no errors in windows event mgr.

    I'm afraid I'm out of ideas.
    Any one else have any thoughts?
    thx in advance.

    **phone responds with 'internal error 2" (snom 320) (log attached at end)

    08:29:49.936 [CM503020]: Normal call termination. Reason: Server Failure
    08:29:49.936 [CM503016]: Call(13): Attempt to reach <sip:23@10.1.1.56:5060;user=phone> failed. Reason: Server Failure
    08:29:49.935 [CM503003]: Call(13): Call to sip:23@10.1.1.56:5060 has failed; Cause: 503 Service Unavailable; warning: ; internal
    08:29:48.885 [CM503025]: Call(13): Calling Ext:Ext.23@[Dev:sip:23@10.1.1.65:2048;line=oh98im9d]
    08:29:48.884 [MS210006] C:13.2:Offer provided. Connection(by pass mode): 10.1.1.54:53408(53409)
    08:29:48.836 [CM503004]: Call(13): Route 1: Ext:Ext.23@[Dev:sip:23@10.1.1.65:2048;line=oh98im9d]
    08:29:48.835 [CM503010]: Making route(s) to <sip:23@10.1.1.56:5060;user=phone>
    08:29:48.835 [MS210000] C:13.1:Offer received. RTP connection: 10.1.1.54:53408(53409)
    08:29:48.834 Remote SDP is set for legC:13.1
    08:29:48.834 [CM505001]: Ext.21: Device info: Device Identified: [Man: Snom;Mod: 3xx series;Rev: General] Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [snom320/8.4.18] PBX contact: [sip:21@10.1.1.56:5060]
    08:29:48.833 [CM503001]: Call(13): Incoming call from Ext.21 to <sip:23@10.1.1.56:5060;user=phone>
    08:29:48.829 [CM500002]: Info on incoming INVITE:
    INVITE sip:23@10.1.1.56:5060;user=phone SIP/2.0
    Via: SIP/2.0/UDP 10.1.1.54:2048;branch=z9hG4bK-ncqn0bfxpxsj;rport=2048
    Max-Forwards: 70
    Contact: <sip:21@10.1.1.54:2048;line=untmdfbo>;reg-id=1
    To: <sip:23@10.1.1.56:5060;user=phone>
    From: "Dean"<sip:21@10.1.1.56:5060>;tag=leeuotlyqb
    Call-ID: 3c29f51fa8e3-cb5qytlzolsd
    CSeq: 2 INVITE
    Session-Expires: 3600;refresher=uas
    Min-SE: 90
    Accept: application/sdp
    Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE
    Proxy-Authorization: Digest username="21",realm="3CXPhoneSystem",nonce="414d535c058a48dc24:33682765bdba49856769b33e5475a968",uri="sip:23@10.1.1.56:5060;user=phone",response="d28fa08ebf1cc9c68725e1d4be5509a9",algorithm=MD5
    Supported: timer, 100rel, replaces, from-change
    User-Agent: snom320/8.4.18
    Allow-Events: talk, hold, refer, call-info
    Content-Length: 0
    X-Serialnumber: 000413316262
    P-Key-Flags: keys="3"

    08:29:47.094 [CM503008]: Call(12): Call is terminated
    08:29:45.771 Currently active calls - 1: [12]
    08:29:45.460 Session 162 of leg C:12.1 is confirmed
    08:29:45.312 [CM503003]: Call(12): Call to sip:23@10.1.1.56:5060 has failed; Cause: 503 Service Unavailable; warning: ; internal
    08:29:45.212 [CM503007]: Call(12): Device joined: sip:99@127.0.0.1:40600;rinstance=0b0d604a29b6f00d
    08:29:45.211 [CM503007]: Call(12): Device joined: sip:21@10.1.1.54:2048;line=untmdfbo
    08:29:45.209 [MS210005] C:12.1:Answer provided. Connection(proxy mode):10.1.1.56:7046(7047)
    08:29:45.208 [MS210001] C:12.3:Answer received. RTP connection[unsecure]: 127.0.0.1:40622(40623)
    08:29:45.207 Remote SDP is set for legC:12.3
    08:29:45.206 [CM505001]: Ext.99: Device info: Device Identified: [Man: 3CX Ltd.;Mod: Voice Mail Menu;Rev: General] Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX Voice Mail Menu] PBX contact: [sip:99@127.0.0.1:5060]
    08:29:45.206 [CM503002]: Call(12): Alerting sip:99@127.0.0.1:40600;rinstance=0b0d604a29b6f00d
    08:29:45.004 [CM503025]: Call(12): Calling Ext:Ext.99@[Dev:sip:99@127.0.0.1:40600;rinstance=0b0d604a29b6f00d]
    08:29:45.003 [MS210004] C:12.3:Offer provided. Connection(proxy mode): 127.0.0.1:7050(7051)
    08:29:44.950 [CM503005]: Call(12): Forwarding: Ext:Ext.99@[Dev:sip:99@127.0.0.1:40600;rinstance=0b0d604a29b6f00d]
    08:29:30.929 [CM503025]: Call(12): Calling Ext:Ext.23@[Dev:sip:23@10.1.1.65:2048;line=oh98im9d]
    08:29:30.928 [MS210006] C:12.2:Offer provided. Connection(by pass mode): 10.1.1.54:63594(63595)


    ***** from snom320 log
    [6] 2/4/2012 08:49:53: webserver::request 65: GET /normal.css HTTP/1.1
    [6] 2/4/2012 08:49:53: webserver::request 67: GET /img/clr.gif HTTP/1.1
    [6] 2/4/2012 08:49:53: webserver::request 68: GET /img/snom_logo.png HTTP/1.1
    [6] 2/4/2012 08:49:53: webserver::request 69: GET /fox.css HTTP/1.1
    [6] 2/4/2012 08:49:53: webserver::request 70: GET /img/separater.png HTTP/1.1
    [6] 2/4/2012 08:49:53: webserver::request 71: GET /normal.css HTTP/1.1
    [6] 2/4/2012 08:49:53: webserver::request 67: GET /img/head.png HTTP/1.1
    [6] 2/4/2012 08:49:54: Timer: webserver/webserver.cpp (151): [close]
    [6] 2/4/2012 08:49:54: Timer: webserver/webserver.cpp (151): [close]
    [6] 2/4/2012 08:49:54: Timer: webserver/webserver.cpp (151): [close]
    [6] 2/4/2012 08:49:54: Timer: webserver/webserver.cpp (151): [close]
    [6] 2/4/2012 08:49:54: Timer: webserver/webserver.cpp (151): [close]
    [6] 2/4/2012 08:49:54: Timer: webserver/webserver.cpp (151): [close]
    [5] 2/4/2012 08:49:55: rtp_port::set_port
    [6] 2/4/2012 08:49:55: Line-Seize subscription was not sent
    [8] 2/4/2012 08:49:55: Goto Best State from 'Idle' (31), force 1
    [8] 2/4/2012 08:49:55: Goto State 'Edit_number' (7) from' Idle' (31), MB 0
    [7] 2/4/2012 08:49:55: set_led: nr 1 id 1 state 1
    [1] 2/4/2012 08:49:55: UDP: could not set reuseaddr option: Bad address (14)
    [1] 2/4/2012 08:49:55: UDP: could not set reuseaddr option: Bad address (14)
    [2] 2/4/2012 08:49:56: Sending post request host = LAPTOP10:8080, file = /outgoing.htm?local=21%4010.1.1.56%3a5060&remote=22&ID=3c29f97699f2-oxe5b2ced707&key=1
    [8] 2/4/2012 08:49:56: DNS: cache lookup: a LAPTOP10.fw.local -> 10.1.1.55
    [5] 2/4/2012 08:49:56: set_audible: RP55 changed=1, update_req=0, adr=
    [6] 2/4/2012 08:49:56: set_additional_addresses
    [8] 2/4/2012 08:49:56: SIP: No special routing, routing to sip:22@10.1.1.56:5060;user=phone
    [8] 2/4/2012 08:49:56: SIP: route pending packet 1006471: url ? sip:22@10.1.1.56:5060;user=phone
    [8] 2/4/2012 08:49:56: SIP: route pending packet 1006471: udp 10.1.1.56 5060
    [8] 2/4/2012 08:49:56: SIP: send Request INVITE (3c29f97699f2-oxe5b2ced707/h3agwa5np3/)
    [9] 2/4/2012 08:49:56: result of get_ip_adr:10.1.1.56 10.1.1.54
    [9] 2/4/2012 08:49:56: result of get_ip_adr:10.1.1.56 10.1.1.54
    [5] 2/4/2012 08:49:56: Dialog 55/58 going to trying
    [7] 2/4/2012 08:49:56: settings::apply_value: callrecord_dialed_time = ' 8:49AM', set.need_apply: 0, finished: 1, need reboot to apply: 0
    [8] 2/4/2012 08:49:56: Goto State 'Calling' (8) from' Edit_number' (7), MB 0
    [8] 2/4/2012 08:49:56: SIP: recvd Response 407 INVITE (3c29f97699f2-oxe5b2ced707/h3agwa5np3/0f616d55)
    [9] 2/4/2012 08:49:56: SIP: clear message_repetition 1006471/3c29f97699f2-oxe5b2ced707
    [8] 2/4/2012 08:49:56: Routing to explicit plan udp 10.1.1.56 5060
    [8] 2/4/2012 08:49:56: SIP: route pending packet 1006472: udp 10.1.1.56 5060
    [8] 2/4/2012 08:49:56: SIP: send Request ACK (3c29f97699f2-oxe5b2ced707/h3agwa5np3/0f616d55)
    [9] 2/4/2012 08:49:56: result of get_ip_adr:10.1.1.56 10.1.1.54
    [9] 2/4/2012 08:49:56: result of get_ip_adr:10.1.1.56 10.1.1.54
    [5] 2/4/2012 08:49:56: sip::process_auth:Match challenge for user=21, realm=3CXPhoneSystem
    [8] 2/4/2012 08:49:56: Routing to explicit plan udp 10.1.1.56 5060
    [8] 2/4/2012 08:49:56: SIP: route pending packet 1006473: udp 10.1.1.56 5060
    [8] 2/4/2012 08:49:56: SIP: send Request INVITE (3c29f97699f2-oxe5b2ced707/h3agwa5np3/)
    [9] 2/4/2012 08:49:56: result of get_ip_adr:10.1.1.56 10.1.1.54
    [9] 2/4/2012 08:49:56: result of get_ip_adr:10.1.1.56 10.1.1.54
    [8] 2/4/2012 08:49:56: SIP: recvd Response 100 INVITE (3c29f97699f2-oxe5b2ced707/h3agwa5np3/)
    [9] 2/4/2012 08:49:56: SIP: clear message_repetition 1006473/3c29f97699f2-oxe5b2ced707
    [5] 2/4/2012 08:49:56: Dialog 55/58 going to proceeding
    [9] 2/4/2012 08:49:56: gui::if_state(55, SIP/2.0 100 Trying)
    [8] 2/4/2012 08:49:56: Goto Best State from 'Calling' (8), force 0
    [8] 2/4/2012 08:49:56: Goto State 'Calling' (8) from' Calling' (8), MB 0
    [8] 2/4/2012 08:49:56: Goto Best State from 'Calling' (8), force 0
    [8] 2/4/2012 08:49:56: Goto State 'Calling' (8) from' Calling' (8), MB 0
    [8] 2/4/2012 08:49:56: Goto Best State from 'Calling' (8), force 0
    [8] 2/4/2012 08:49:56: Goto State 'Calling' (8) from' Calling' (8), MB 0
    [8] 2/4/2012 08:49:56: SIP: recvd Response 500 INVITE (3c29f97699f2-oxe5b2ced707/h3agwa5np3/bb2fa95a)
    [9] 2/4/2012 08:49:56: SIP: clear message_repetition 1006473/3c29f97699f2-oxe5b2ced707
    [8] 2/4/2012 08:49:56: Routing to explicit plan udp 10.1.1.56 5060
    [8] 2/4/2012 08:49:56: SIP: route pending packet 1006474: udp 10.1.1.56 5060
    [8] 2/4/2012 08:49:56: SIP: send Request ACK (3c29f97699f2-oxe5b2ced707/h3agwa5np3/bb2fa95a)
    [9] 2/4/2012 08:49:56: result of get_ip_adr:10.1.1.56 10.1.1.54
    [9] 2/4/2012 08:49:56: result of get_ip_adr:10.1.1.56 10.1.1.54
    [5] 2/4/2012 08:49:56: Dialog 55/58 going to terminated
    [9] 2/4/2012 08:49:56: gui::if_state(55, SIP/2.0 500 Server Internal Error)
    [8] 2/4/2012 08:49:56: Goto Best State from 'Calling' (8), force 0
    [8] 2/4/2012 08:49:56: Goto State 'Calling' (8) from' Calling' (8), MB 0
    [2] 2/4/2012 08:49:56: Sending post request host = LAPTOP10:8080, file = /disconnected.htm?local=21%4010.1.1.56%3a5060&remote=22&ID=3c29f97699f2-oxe5b2ced707&key=1
    [8] 2/4/2012 08:49:56: DNS: cache lookup: a LAPTOP10.fw.local -> 10.1.1.55
    [8] 2/4/2012 08:49:56: Goto Best State from 'Calling' (8), force 0
    [8] 2/4/2012 08:49:56: Goto State 'Terminated' (14) from' Calling' (8), MB 0
    [7] 2/4/2012 08:49:56: set_led: nr 1 id 1 state 0
    [9] 2/4/2012 08:49:56: SIP: delete connection 55 in 0 secs
    [9] 2/4/2012 08:49:56: Timer: Registering with timeout of 0 ms
    [9] 2/4/2012 08:49:56: SIP: delete connection 55 in 0 secs
    [9] 2/4/2012 08:49:56: Timer: Registering with timeout of 0 ms
    [6] 2/4/2012 08:49:56: Timer: sip/sip.cpp (1674): [mark_for_deletion]
    [5] 2/4/2012 08:49:56: set_audible: RP55 changed=1, update_req=0, adr=
    [6] 2/4/2012 08:49:57: Timer: gui/gui_state_terminated.cpp (385): [enter_on_terminated]
    [8] 2/4/2012 08:49:58: Goto Best State from 'Terminated' (14), force 1
    [8] 2/4/2012 08:49:58: Goto State 'Idle' (31) from' Terminated' (14), MB 0
    [6] 2/4/2012 08:49:59: Timer: gui/gui_state_idle.cpp (4087): [enter_on_idle]
    [6] 2/4/2012 08:50:01: webserver::request 72: GET /log.htm HTTP/1.1
     
Thread Status:
Not open for further replies.