[Users] presence in openser 1.2 ... cannot insert row?

Daniel-Constantin Mierla daniel at voice-system.ro
Thu Apr 12 19:40:33 CEST 2007


Hello,

the id column in dbtext tables didn't have the auto increment flag set. 
I have just committed on svn the fix.

Cheers,
Daniel
 

On 04/12/07 20:16, Cesc wrote:
> Hi,
>
> I am testing the presence in openser1.2 ... running a ser.0.9.6 as a
> registrar/proxy which forwards all presence messages to openser.
> As a client, I use xlite 3.0 ...
>
> I had an old semi-functional openser working, pre-1.2 ... and now I
> upgraded to 1.2 from svn and it ain't working :)   The config file I
> modified, as well as creating the DBTEXT files (all) from scratch
> using the textdb.sh script.
>
> Now, you can see the attached config file ... and the whireshark trace
> with the subscribe and publish messages received ...
> What happens can be seen here, in the log I get ... most interesting
> are the lines with ERROR  written on them ;)
> They tell that a new row could not be inserted ... and that some
> lookup failed on the database ... I guess a familiar eye can catch
> that easy.
>
>
> 4(2517) parse_headers: flags=78
> 4(2517) t_lookup_request: start searching: hash=50044, isACK=0
> 4(2517) DEBUG: RFC3261 transaction matching failed
> 4(2517) DEBUG: t_lookup_request: no transaction found
> 4(2517) 
> ============================================================================================= 
>
> 4(2517) The request method used is to [SUBSCRIBE] information.
> (handle subscribe)
> 4(2517) 
> ============================================================================================= 
>
> 1(2513) SIP Request:
> 1(2513)  method:  <SUBSCRIBE>
> 1(2513)  uri:     <sip:Chelsea at cafes.org>
> 1(2513)  version: <SIP/2.0>
> 1(2513) parse_headers: flags=2
> 1(2513) Found param type 232, <branch> = <z9hG4bKa4e7.bd4e2945.0>; 
> state=16
> 1(2513) end of header reached, state=5
> 1(2513) parse_headers: Via found, flags=2
> 1(2513) parse_headers: this is the first via
> 1(2513) After parse_msg...
> 1(2513) preparing to run routing scripts...
> 1(2513) parse_headers: flags=100
> 1(2513) Found param type 232, <branch> =
> <z9hG4bK-d87543-2641a76387057623-1--d87543->; state=6
> 1(2513) Found param type 235, <rport> = <4326>; state=16
> 1(2513) end of header reached, state=5
> 1(2513) parse_headers: Via found, flags=100
> 1(2513) parse_headers: this is the second via
> 1(2513) DEBUG:maxfwd:is_maxfwd_present: value = 16
> 1(2513) 
> ============================================================================================== 
>
> 1(2513) parse_headers: flags=10
> 1(2513) DEBUG:parse_to:end of header reached, state=10
> 1(2513) DBUG:parse_to: display={}, ruri={sip:Chelsea at cafes.org}
> 1(2513) DEBUG: get_hdr_field: <To> [25]; uri=[sip:Chelsea at cafes.org]
> 1(2513) DEBUG: to body [<sip:Chelsea at cafes.org>
> ]
> 1(2513) DEBUG: add_param: tag=1753b200
> 1(2513) DEBUG:parse_to:end of header reached, state=29
> 1(2513) DBUG:parse_to: display={"X-lite user 1"}, 
> ruri={sip:Klaas at cafes.org}
> 1(2513) New Message received: [7] from [sip:Klaas at cafes.org]
> 1(2513) Request method used:[SUBSCRIBE].
> 1(2513) 
> ============================================================================================= 
>
> 1(2513) DEBUG: t_newtran:  T on entrance=0xffffffff
> 1(2513) parse_headers: flags=ffffffffffffffff
> 1(2513) get_hdr_field: cseq <CSeq>: <1> <SUBSCRIBE>
> 1(2513) DEBUG: get_hdr_body : content_length=0
> 1(2513) found end of header
> 1(2513) parse_headers: flags=78
> 1(2513) t_lookup_request: start searching: hash=32330, isACK=0
> 1(2513) DEBUG: RFC3261 transaction matching failed
> 1(2513) DEBUG: t_lookup_request: no transaction found
> 1(2513) 
> ============================================================================================= 
>
> 1(2513) The request method used is to [SUBSCRIBE] information.
> (handle subscribe)
> 1(2513) 
> ============================================================================================= 
>
> 1(2513) parse_headers: flags=ffffffffffffffff
> 1(2513) PRESENCE: handle_subscribe: 'expires' found
> 1(2513) PRESENCE: handle_subscribe: lexpire= 3600
> 1(2513) PRESENCE: handle_subscribe: 'To' header ALREADY PARSED:
> <sip:Chelsea at cafes.org>
> 1(2513) PRESENCE:handle_subscribe: generating to_tag
> 1(2513) PRESENCE :proces_rr: out rr 
> [<sip:192.168.1.150;ftag=1753b200;lr=on>]
> 1(2513) DBT:dbt_query: new res with 2 cols
> 1(2513) DBT:dbt_result_new: new res with 2 cols
> 1(2513) PRESENCE:handle_subscribe:The query in table watches returned 
> no result
> 1(2513) DBT:dbt_table_check_row: NULL value not allowed - field 0
> 1(2513) DBT:db_insert: cannot insert the new row!!
> 1(2513) DBT:db_insert: make clean!
> 1(2513) PRESENCE:handle_subscribe: ERROR while inserting into watchers 
> table
> 1(2513) PRESENCE:handle_subscribe: ERROR occured
> 1(2513) DEBUG: cleanup_uac_timers: RETR/FR timers reset
> 1(2513) DEBUG: add_to_tail_of_timer[2]: 0xb5d79c78 (45)
> 1(2513) DEBUG:tm:UNREF_UNSAFE: after is 0
> 1(2513) DEBUG:destroy_avp_list: destroying list (nil)
> 1(2513) receive_msg: cleaning up
> 2(2515) SIP Request:
> 2(2515)  method:  <PUBLISH>
> 2(2515)  uri:     <sip:Klaas at cafes.org>
> 2(2515)  version: <SIP/2.0>
> 2(2515) parse_headers: flags=2
> 2(2515) Found param type 232, <branch> = <z9hG4bK5aa3.0e4b2fb7.0>; 
> state=16
> 2(2515) end of header reached, state=5
> 2(2515) parse_headers: Via found, flags=2
> 2(2515) parse_headers: this is the first via
> 2(2515) After parse_msg...
> 2(2515) preparing to run routing scripts...
> 2(2515) parse_headers: flags=100
> 2(2515) Found param type 232, <branch> =
> <z9hG4bK-d87543-7441d6073759ed7a-1--d87543->; state=6
> 2(2515) Found param type 235, <rport> = <4326>; state=16
> 2(2515) end of header reached, state=5
> 2(2515) parse_headers: Via found, flags=100
> 2(2515) parse_headers: this is the second via
> 2(2515) DEBUG:maxfwd:is_maxfwd_present: value = 16
> 2(2515) 
> ============================================================================================== 
>
> 2(2515) parse_headers: flags=10
> 2(2515) DEBUG:parse_to:end of header reached, state=10
> 2(2515) DBUG:parse_to: display={"X-lite user 1"}, 
> ruri={sip:Klaas at cafes.org}
> 2(2515) DEBUG: get_hdr_field: <To> [38]; uri=[sip:Klaas at cafes.org]
> 2(2515) DEBUG: to body ["X-lite user 1"<sip:Klaas at cafes.org>
> ]
> 2(2515) DEBUG: add_param: tag=eb194522
> 2(2515) DEBUG:parse_to:end of header reached, state=29
> 2(2515) DBUG:parse_to: display={"X-lite user 1"}, 
> ruri={sip:Klaas at cafes.org}
> 2(2515) New Message received: [5] from [sip:Klaas at cafes.org]
> 2(2515) Request method used:[PUBLISH].
> 2(2515) 
> ============================================================================================= 
>
> 2(2515) DEBUG: t_newtran:  T on entrance=0xffffffff
> 2(2515) parse_headers: flags=ffffffffffffffff
> 2(2515) get_hdr_field: cseq <CSeq>: <1> <PUBLISH>
> 2(2515) DEBUG: get_hdr_body : content_length=439
> 2(2515) found end of header
> 2(2515) parse_headers: flags=78
> 2(2515) t_lookup_request: start searching: hash=15013, isACK=0
> 2(2515) DEBUG: RFC3261 transaction matching failed
> 2(2515) DEBUG: t_lookup_request: no transaction found
> 2(2515) 
> ============================================================================================= 
>
> 2(2515) The request method used is to [PUBLISH] information. (handle 
> publish)
> 2(2515) 
> ============================================================================================= 
>
> 2(2515) parse_headers: flags=ffffffffffffffff
> 2(2515) PRESENCE:handle_publish: SIP-If-Match not found
> 2(2515) PRESENCE: generate_ETag: etag= a.1175401932.2515.3 / 19
>  2(2515) PRESENCE:handle_publish: new etag  = a.1175401932.2515.3
> 2(2515) PRESENCE: handle_publish: 'expires' found
> 2(2515) PRESENCE: handle_publish: lexpire= 3600
> 2(2515) PRESENCE: handle_publish: 'To' header ALREADY PARSED:
> <sip:Klaas at cafes.org>
> 2(2515) parse_headers: flags=ffffffffffffffff
> 2(2515) PRESENCE:update_presentity: inserting 7 cols intotable
> 2(2515) DBT:dbt_table_check_row: NULL value not allowed - field 0
> 2(2515) DBT:db_insert: cannot insert the new row!!
> 2(2515) DBT:db_insert: make clean!
> 2(2515) PRESENCE:update_presentity: Error while inserting new presentity
> 2(2515) PRESENCE:update_presentity: ERROR occured
> 2(2515) PRESENCE:handle_publish: ERROR occured while updating presentity
> 2(2515) PRESENCE: handle_publish: ERROR occured
> 2(2515) DEBUG: cleanup_uac_timers: RETR/FR timers reset
> 2(2515) DEBUG: add_to_tail_of_timer[2]: 0xb5d77d08 (45)
> 2(2515) DEBUG:tm:UNREF_UNSAFE: after is 0
> 2(2515) DEBUG:destroy_avp_list: destroying list (nil)
> 2(2515) receive_msg: cleaning up
> 4(2517) parse_headers: flags=ffffffffffffffff
> 4(2517) PRESENCE: handle_subscribe: 'expires' found
> 4(2517) PRESENCE: handle_subscribe: lexpire= 3600
> 4(2517) PRESENCE: handle_subscribe: 'To' header ALREADY PARSED:
> <sip:Klaas at cafes.org>
> 4(2517) PRESENCE:handle_subscribe: generating to_tag
> 4(2517) PRESENCE :proces_rr: out rr 
> [<sip:192.168.1.150;ftag=e7740874;lr=on>]
> 4(2517)
>        [p_user]= Klaas  [p_domain]= cafes.org
>        [w_user]= Klaas [w_domain]= cafes.org
> 4(2517) [event]= presence.winfo
>        [staus]= active
>        [expires]= 3600
> 4(2517) [to_tag]= 10.2517.1175401973.2
>        [from_tag]= e7740874
> 4(2517) PRESENCE: update_subscription ...
> 4(2517)
>        [p_user]= Klaas  [p_domain]= cafes.org
>        [w_user]= Klaas [w_domain]= cafes.org
> 4(2517) [event]= presence.winfo
>        [staus]= active
>        [expires]= 3600
> 4(2517) [to_tag]= 10.2517.1175401973.2
>        [from_tag]= e7740874
> 4(2517) expires: 3600
> 4(2517) PRESENCE:update_subscription:Inserting into database:
> n_query_cols:14
> 4(2517) [0] = to_user Klaas
> 4(2517) [1] = to_domain cafes.org
> 4(2517) [2] = from_user Klaas
> 4(2517) [3] = from_domain cafes.org
> 4(2517) [4] = event presence.winfo
> 4(2517) [5] = event_id
> 4(2517) [6] = callid MGUwMzgyNGFiMWE5ZGIxZjg1NGQwNDI5N2JlOTFmYjA.
> 4(2517) [7] = to_tag 10.2517.1175401973.2
> 4(2517) [8] = from_tag e7740874
> 4(2517) [9] = contact sip:Klaas at 192.168.3.172:4326
> 4(2517) [10] = status active
> 4(2517) [11] = cseq 1
> 4(2517) DBT:dbt_table_check_row: NULL value not allowed - field 0
> 4(2517) DBT:db_insert: cannot insert the new row!!
> 4(2517) DBT:db_insert: make clean!
> 4(2517) PRESENCE:update_subscription: ERROR while storing new 
> subscription
> 4(2517) PRESENCE:update_presentity: ERROR occured
> 4(2517) PRESENCE:handle_subscribe: ERROR while updating database
> 4(2517) PRESENCE:handle_subscribe: ERROR occured
> 4(2517) DEBUG: cleanup_uac_timers: RETR/FR timers reset
> 4(2517) DEBUG: add_to_tail_of_timer[2]: 0xb5d763b8 (45)
> 4(2517) DEBUG:tm:UNREF_UNSAFE: after is 0
> 4(2517) DEBUG:destroy_avp_list: destroying list (nil)
> 4(2517) receive_msg: cleaning up
> 3(2516)  1(2513) SIP Request:
> 1(2513)  method:  <SUBSCRIBE>
> 1(2513)  uri:     <sip:Chelsea at cafes.org>
> 1(2513)  version: <SIP/2.0>
> 1(2513) parse_headers: flags=2
> 1(2513) Found param type 232, <branch> = <z9hG4bKa4e7.bd4e2945.0>; 
> state=16
> 1(2513) end of header reached, state=5
> 1(2513) parse_headers: Via found, flags=2
> 1(2513) parse_headers: this is the first via
> 1(2513) After parse_msg...
> 1(2513) preparing to run routing scripts...
> 1(2513) parse_headers: flags=100
> 1(2513) Found param type 232, <branch> =
> <z9hG4bK-d87543-2641a76387057623-1--d87543->; state=6
> 1(2513) Found param type 235, <rport> = <4326>; state=16
> 1(2513) end of header reached, state=5
> 1(2513) parse_headers: Via found, flags=100
> 1(2513) parse_headers: this is the second via
> 1(2513) DEBUG:maxfwd:is_maxfwd_present: value = 16
> 1(2513) 
> ============================================================================================== 
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> Users mailing list
> Users at openser.org
> http://openser.org/cgi-bin/mailman/listinfo/users




More information about the Users mailing list