Bugs item #2593088, was opened at 2009-02-12 13:48 Message generated for change (Comment added) made by nobody You can respond by visiting: https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=2593088&group_id=232389
Please note that this message will contain a full copy of the comment thread, including the initial issue submission, for this request, not just the latest update. Category: None Group: None Status: Open Resolution: None Priority: 5 Private: No Submitted By: Nobody/Anonymous (nobody) Assigned to: Nobody/Anonymous (nobody) Summary: Crash with db_postgres and presence Initial Comment: (submitted by [email protected]) The problem is as follows - a query is executed, but for some reason the results from the previous one are read back from the DB driver, which in turn makes opensips to crash as the number of columns is lower and it tries to dereference stuff that doesn't exist. Appended are the log and the backtrace: Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_submit_query: 0x8197240 PQsendQuery(select status,reason from watchers where presentity_uri='sip:bbb%[email protected]' AND watcher_username='aaa%40ccc.com' AND watcher_domain='10.2.30.5' AND event='presence') Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:core:db_new_result: allocate 28 bytes for result set at 0x81a0948 Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_store_result: 0x8197240 PQresultStatus(PGRES_TUPLES_OK) PQgetResult(0x94c0300) Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_get_columns: 1 columns returned from the query Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:core:db_allocate_columns: allocate 16 bytes for result columns at 0x819ecd0 Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_get_columns: RES_NAMES(0x819ecd8)[0]=[username] Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_get_columns: use DB_STRING result type Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_convert_rows: allocate for 1 columns 4 bytes in row buffer at 0x819d5b8 Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:core:db_allocate_rows: allocate 28 bytes for result rows and values at 0x819f870 Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_convert_rows: PQgetvalue(0x8197240,0,0)=[[email protected]] Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_convert_rows: allocated 11 bytes for row_buf[0] at 0x819d5c8 Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_convert_rows: [0][0] column[username]=[[email protected]] Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_str2val: converting STRING [[email protected]] Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:db_postgres_convert_rows: freeing row buffer at 0x819d5b8 Feb 12 13:42:59 f-ast2 opensips[29504]: DBG:db_postgres:free_query: PQclear(0x94c0300) result set Feb 12 13:42:59 f-ast2 opensips[29507]: DBG:db_postgres:db_postgres_store_result: 0x8197100 PQresultStatus(PGRES_TUPLES_OK) PQgetResult(0x94bb108) Feb 12 13:42:59 f-ast2 kernel: [842163.893756] opensips[29504]: segfault at 1 ip b77b98c6 sp bff1ab30 error 4 in presence.so[b7790000+31000] Core was generated by `opensips'. Program terminated with signal 11, Segmentation fault. [New process 29504] #0 0xb77b98c6 in get_db_subs_auth (subs=0xbff1acf4, found=0xbff1ad94) at subscribe.c:1980 1980 subs->reason.len= strlen(row_vals[1].val.string_val); (gdb) bt #0 0xb77b98c6 in get_db_subs_auth (subs=0xbff1acf4, found=0xbff1ad94) at subscribe.c:1980 #1 0xb77ba5cc in handle_subscribe (msg=0x819acb8, str1=0x0, str2=0x0) at subscribe.c:630 #2 0x08055591 in do_action (a=0x8195940, msg=0x819acb8) at action.c:961 #3 0x080541e2 in run_action_list (a=0x8195940, msg=0x819acb8) at action.c:139 #4 0x08056ecd in do_action (a=0x8195fe0, msg=0x819acb8) at action.c:705 #5 0x080541e2 in run_action_list (a=0x8195fe0, msg=0x819acb8) at action.c:139 #6 0x08057529 in do_action (a=0x8196048, msg=0x819acb8) at action.c:711 #7 0x080541e2 in run_action_list (a=0x81953d0, msg=0x819acb8) at action.c:139 #8 0x08056914 in do_action (a=0x8192808, msg=0x819acb8) at action.c:119 #9 0x080541e2 in run_action_list (a=0x8192808, msg=0x819acb8) at action.c:139 #10 0x08056ecd in do_action (a=0x8192870, msg=0x819acb8) at action.c:705 #11 0x080541e2 in run_action_list (a=0x818d6b8, msg=0x819acb8) at action.c:139 #12 0x08057ee1 in run_top_route (a=0x818d6b8, msg=0x819acb8) at action.c:119 #13 0x0809228c in receive_msg ( buf=0x8164100 "SUBSCRIBE sip:bbb%[email protected];transport=UDP SIP/2.0\r\nVia: SIP/2.0/UDP 10.2.2.179:5060;branch=z9hG4bK-d8754z-1c3f735ee1e02d36-1---d8754z-\r\nMax-Forwards: 69\r\nContact: <sip:aaa%[email protected]"..., len=793, rcv_info=0xbff1bad4) at receive.c:165 #14 0x080cdf4b in udp_rcv_loop () at udp_server.c:449 #15 0x0806c3af in main (argc=1, argv=0xbff1bc64) at main.c:778 ---------------------------------------------------------------------- Comment By: Nobody/Anonymous (nobody) Date: 2009-02-12 15:44 Message: I have been looking into the problem for some time and it seems like there's a race condition in the postgresql driver somewhere. I have seen how a query A is made, then query B hits, and then the part that sent B sees the results of A and crashes opensips. I'll try to find the place where the lock should happen, but I'll need to get a bit more familiar with the types of locking primitives used. ---------------------------------------------------------------------- You can respond by visiting: https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=2593088&group_id=232389 _______________________________________________ Devel mailing list [email protected] http://lists.opensips.org/cgi-bin/mailman/listinfo/devel
