[OpenSIPS-Users] OpenSIPS returns 400 Bad Request for PUBLISH

[Sanjeev BA]

Error logs from OpenSIPS console.

 

Oct 14 14:01:46 [4880] DBG:core:parse_msg:  method:  <PUBLISH>

Oct 14 14:01:46 [4880] DBG:core:parse_msg:  uri:
<sip:tester at imsdemo.com>

Oct 14 14:01:46 [4880] DBG:core:parse_msg:  version: <SIP/2.0>

Oct 14 14:01:46 [4880] DBG:core:parse_headers: flags=2

Oct 14 14:01:46 [4880] DBG:core:get_hdr_field: cseq <CSeq>: <1> <PUBLISH>

Oct 14 14:01:46 [4880] DBG:core:parse_to: end of header reached, state=10

Oct 14 14:01:46 [4880] DBG:core:parse_to: display={},
ruri={sip:tester at imsdemo.com}

Oct 14 14:01:46 [4880] DBG:core:get_hdr_field: <To> [27];
uri=[sip:tester at imsdemo.com] 

Oct 14 14:01:46 [4880] DBG:core:get_hdr_field: to body
[<sip:tester at imsdemo.com>

]

Oct 14 14:01:46 [4880] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK2559870494smg>; state=6

Oct 14 14:01:46 [4880] DBG:core:parse_via_param: found param type 238,
<transport> = <UDP>; state=16

Oct 14 14:01:46 [4880] DBG:core:parse_via: end of header reached, state=5

Oct 14 14:01:46 [4880] DBG:core:parse_headers: via found, flags=2

Oct 14 14:01:46 [4880] DBG:core:parse_headers: this is the first via

Oct 14 14:01:46 [4880] DBG:core:receive_msg: After parse_msg...

Oct 14 14:01:46 [4880] DBG:core:receive_msg: preparing to run routing
scripts...

Oct 14 14:01:46 [4880] DBG:maxfwd:is_maxfwd_present: value = 70 

Oct 14 14:01:46 [4880] DBG:core:parse_headers: flags=80

Oct 14 14:01:46 [4880] DBG:uri:has_totag: no totag

Oct 14 14:01:46 [4880] DBG:core:parse_headers: flags=78

Oct 14 14:01:46 [4880] DBG:tm:t_lookup_request: start searching: hash=30511,
isACK=0

Oct 14 14:01:46 [4880] DBG:tm:matching_3261: RFC3261 transaction matching
failed

Oct 14 14:01:46 [4880] DBG:tm:t_lookup_request: no transaction found

Oct 14 14:01:46 [4880] DBG:core:parse_headers: flags=200

Oct 14 14:01:46 [4880] DBG:core:get_hdr_field: content_length=0

Oct 14 14:01:46 [4880] DBG:core:get_hdr_field: found end of header

Oct 14 14:01:46 [4880] DBG:rr:find_first_route: No Route headers found

Oct 14 14:01:46 [4880] DBG:rr:loose_route: There is no Route HF

Oct 14 14:01:46 [4880] ERROR:rr:w_record_route: Double attempt to
record-route

Oct 14 14:01:46 [4880] DBG:core:grep_sock_info: checking if host==us: 11==12
&&  [imsdemo.com] == [10.89.10.235]

Oct 14 14:01:46 [4880] DBG:core:grep_sock_info: checking if port 5060
matches port 5060

Oct 14 14:01:46 [4880] DBG:core:parse_headers: flags=ffffffffffffffff

Oct 14 14:01:46 [4880] DBG:presence:search_event: start event= [presence]

Oct 14 14:01:46 [4880] DBG:presence:handle_publish: SIP-If-Match header not
found

Oct 14 14:01:46 [4880] DBG:presence:generate_ETag: etag=
a.1255496470.4880.1.0 / 21

Oct 14 14:01:46 [4880] DBG:presence:handle_publish: new etag  =
a.1255496470.4880.1.0 

Oct 14 14:01:46 [4880] DBG:presence:handle_publish: Expires header found,
value= 3600

Oct 14 14:01:46 [4880] ERROR:presence:handle_publish: No E-Tag and no body
found

Oct 14 14:01:46 [4880] DBG:core:parse_headers: flags=ffffffffffffffff

Oct 14 14:01:46 [4880] DBG:core:check_via_address: params 10.254.140.195,
10.254.140.195, 0

Oct 14 14:01:46 [4880] DBG:sl:run_sl_callbacks: callback id 0 entered

Oct 14 14:01:46 [4880] DBG:tm:t_newtran: transaction on entrance=(nil)

Oct 14 14:01:46 [4880] DBG:core:parse_headers: flags=ffffffffffffffff

Oct 14 14:01:46 [4880] DBG:core:parse_headers: flags=78

Oct 14 14:01:46 [4880] DBG:tm:t_lookup_request: start searching: hash=30511,
isACK=0

Oct 14 14:01:46 [4880] DBG:tm:matching_3261: RFC3261 transaction matching
failed

Oct 14 14:01:46 [4880] DBG:tm:t_lookup_request: no transaction found

Oct 14 14:01:46 [4880] DBG:tm:run_reqin_callbacks: trans=0xb3a09a30,
callback type 1, id 0 entered

Oct 14 14:01:46 [4880] DBG:tm:cleanup_uac_timers: RETR/FR timers reset

Oct 14 14:01:46 [4880] DBG:tm:insert_timer_unsafe: [2]: 0xb3a09a78 (41)

Oct 14 14:01:46 [4880] DBG:tm:t_unref: UNREF_UNSAFE: after is 0

Oct 14 14:01:46 [4880] DBG:core:destroy_avp_list: destroying list (nil)

Oct 14 14:01:46 [4880] DBG:core:receive_msg: cleaning up

Oct 14 14:01:51 [4885] DBG:tm:timer_routine: timer routine:2,tl=0xb3a09a78
next=(nil), timeout=41

Oct 14 14:01:51 [4885] DBG:tm:wait_handler: removing 0xb3a09a30 from table 

Oct 14 14:01:51 [4885] DBG:tm:delete_cell: delete transaction 0xb3a09a30

Oct 14 14:01:51 [4885] DBG:tm:wait_handler: done

Oct 14 14:02:50 [4885] DBG:presence:update_db_subs: delete expired

Oct 14 14:02:50 [4885] DBG:db_mysql:db_mysql_do_prepared_query:
conn=0x8167ee8 (tail=135699504) MC=0x816ba48

Oct 14 14:02:50 [4885] DBG:db_mysql:db_mysql_do_prepared_query: new
query=|delete from active_watchers where expires<?|

Oct 14 14:02:50 [4885] DBG:db_mysql:db_mysql_do_prepared_query: new
statement(0x8169f70) on connection: (0x8167ee8) 0x8169c30

Oct 14 14:02:50 [4885] DBG:db_mysql:db_mysql_do_prepared_query: set values
for the statement run

Oct 14 14:02:50 [4885] DBG:db_mysql:db_mysql_val2bind: added val (0): len=4;
type=3; is_null=0

Oct 14 14:02:50 [4885] DBG:db_mysql:db_mysql_do_prepared_query: doing
BIND_PARAM in...

Oct 14 14:02:50 [4885] DBG:presence:msg_watchers_clean: cleaning pending
subscriptions

Oct 14 14:02:50 [4885] DBG:core:db_do_query: SYNC-DBG - SELECT successfully
executed!

 

 

Kindly advice.

 

Regards

Sanjeev

 

 

Hi,

 

I am observing an error response from OpenSIPS. It returns 400 Bad Request
for the following PUBLISH request.

 

PUBLISH sip:tester at imsdemo.com SIP/2.0

Expires: 3600

Event: presence

Privacy: None

Accept-Contact: *;+g.3gpp.Pua;explicit

Contact: sip:tester at 10.10.10.20


Call-ID: 2189952363 at imsdemo.com

CSeq: 1 PUBLISH

Max-Forwards: 70

From: <sip:tester at imsdemo.com>;tag=1842963402

To: <sip:tester at imsdemo.com>

Via:SIP/2.0/UDP 10.254.140.195:5060;branch=z9hG4bK132770389smg;transport=UDP

Content-Length: 0

 

 

Regards,

Sanjeev

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.opensips.org/pipermail/users/attachments/20091014/b0c02063/attachment-0001.htm