<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
<head>
<meta content="text/html; charset=ISO-8859-1"
http-equiv="Content-Type">
</head>
<body bgcolor="#ffffff" text="#000000">
I've got some more debug information,<br>
but it almost looks like a race condition.<br>
<br>
When I turn of all debugging the problem occurs more often.<br>
When I turn on debugging (level 4 or 5) I almost never see the
error.<br>
<br>
But I finally have some debugging info:<br>
<br>
Oct 18 19:40:53 localhost /sbin/kamailio[29227]: DEBUG: <core>
[sr_module.c:828]: DEBUG: init_mod_child (96): permissions<br>
Oct 18 19:40:53 localhost /sbin/kamailio[29227]: DEBUG: <core>
[db.c:294]: connection 0x958390 found in pool<br>
Oct 18 19:40:53 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_val.c:163]: PQescapeStringConn: in: 7 chars, out: 7 chars<br>
Oct 18 19:40:53 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_dbase.c:149]: 0x959aa0 PQsendQuery(select table_version from
version where table_name='trusted')<br>
Oct 18 19:40:53 localhost /sbin/kamailio[29227]: DEBUG: <core>
[db_res.c:118]: allocate 48 bytes for result set at 0x94d790<br>
<br>
Then 47 seconds later (in the mean time, nothing is reported for pid
29227):<br>
<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_dbase.c:403]: 0x959aa0 PQresultStatus(PGRES_TUPLES_OK)
PQgetResult(0x139aca20)<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_res.c:108]: 1 columns returned from the query<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: <core>
[db_res.c:155]: allocate 8 bytes for result names at 0x94b1f0<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: <core>
[db_res.c:165]: allocate 4 bytes for result types at 0x942140<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_res.c:126]: allocate 16 bytes for RES_NAMES[0] at 0x9599b0<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_res.c:133]: RES_NAMES(0x9599b0)[0]=[password]<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_res.c:166]: use DB1_STRING result type<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_res.c:222]: allocate for 1 columns 8 bytes in row buffer at
0x959538<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: <core>
[db_res.c:184]: allocate 16 bytes for rows at 0x9598d8<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_res.c:243]: PQgetvalue(0x959aa0,0,0)=[mAC4QMyW262E]<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_res.c:252]: [0][0] Column[password]=[mAC4QMyW262E]<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: <core>
[db_row.c:119]: allocate 32 bytes for row values at 0x94d820<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: <core>
[db_val.c:117]: converting STRING [mAC4QMyW262E]<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: <core>
[db_val.c:127]: allocate 13 bytes memory for STRING at 0x9596d0<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_res.c:267]: freeing row buffer at 0x959538<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: DEBUG: db_postgres
[km_dbase.c:302]: PQclear(0x139aca20) result set<br>
Oct 18 19:41:40 localhost /sbin/kamailio[29227]: ERROR: <core>
[db.c:387]: invalid type (3) or nul (0) version columns for trusted<br>
<br>
I have more debugging lines if someone has an idea.<br>
<br>
But it appears that pid 29227 is sending a query, and when it
continues it's working with the results from a completely different
query.<br>
<br>
Regards,<br>
Robert<br>
<br>
On 10/12/2010 04:30 PM, Robert Verspuy wrote:
<blockquote cite="mid:4CB47117.6020509@exa-omicron.nl" type="cite">
<meta http-equiv="content-type" content="text/html;
charset=ISO-8859-1">
I've got a strange issue with the latest kamailio. I also had this
problem with kamailio 3.0.3 downloaded from the webpage.<br>
<br>
I can start kamailio, but after a while (sometimes within one
minuten, sometimes after an hour),<br>
I get the following log errors:<br>
<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26621]: ERROR: <core>
[db.c:387]: invalid type (3) or nul (0) version columns for
trusted<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26621]: ERROR: <core>
[db.c:405]: querying version for table trusted<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26621]: ERROR: permissions
[trusted.c:249]: error during table version check.<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26621]: ERROR: <core>
[sr_module.c:832]: init_mod_child(): Error while initializing
module permissions (//lib/kamailio/modules_k/permissions.so)<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26621]: ERROR: <core>
[pt.c:481]: ERROR: fork_tcp_process(): init_child failed for
process 10, pid 26621, "tcp receiver child=0"<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26621]: ERROR: <core>
[tcp_main.c:4811]: ERROR: tcp_main: fork failed: Success<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26625]: : <core>
[pass_fd.c:103]: ERROR: recv_all: 1st recv on 21 failed:
Connection reset by peer<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26625]: : <core>
[tcp_main.c:3323]: ERROR: handle_tcp_child: read from tcp child 0
(pid 26621, no 10) Connection reset by peer [104]<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26625]: : <core>
[pass_fd.c:293]: ERROR: receive_fd: EOF on 19<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26611]: ALERT: <core>
[main.c:738]: child process 26621 exited normally, status=255<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26611]: INFO: <core>
[main.c:756]: INFO: terminating due to SIGCHLD<br>
Oct 12 15:46:24 sp01 /sbin/kamailio[26625]: INFO: <core>
[main.c:807]: INFO: signal 15 received<br>
<br>
Looking at the error message, it thinks that the column type of
table_version in the table version is a string (type 3), and it
should be an int (type 1).<br>
But in the database it really is an int.<br>
<br>
When I run kamailio with debugging on level 5, I see that it's
trying to run the "select table_version from version where
table_name='trusted'" several times when kamailio starts (for
every child thread).<br>
And then minutes, of even an hour later, it suddenly continues
with that check, but based on a database response from another
query.<br>
This is the "select password from subscriber ....etc...".<br>
And that column is indeed an string.<br>
<br>
I'm using PostgreSQL 8.4 as server,<br>
but maybe someone has seen this before, or now where I have to
start looking?<br>
I first saw it yesterday when started to use the permissions
module.<br>
I only see this with the trusted table,<br>
And always it uses the "select password from subscriber ... "
response when giving this error.<br>
<br>
So is this an error in the permissions module / trusted.c file?<br>
or something in auth_db that's not freeing the response correctly?<br>
<br>
Strange thing is, that is sometimes happens very quick, and
sometimes it can take an half hour or hour.<br>
<br>
I can mail the full log if anybody is interested and thinks he/she
can help me.<br>
<br>
With kind regards,<br>
Robert Verspuy<br>
<br>
<br>
<div class="moz-signature">-- <br>
<b>Exa-Omicron</b><br>
Patroonsweg 10<br>
3892 DB Zeewolde<br>
Tel.: 088-OMICRON (66 427 66)<br>
<a moz-do-not-send="true" class="moz-txt-link-freetext"
href="http://www.exa-omicron.nl">http://www.exa-omicron.nl</a></div>
<pre wrap="">
<fieldset class="mimeAttachmentHeader"></fieldset>
_______________________________________________
sr-dev mailing list
<a class="moz-txt-link-abbreviated" href="mailto:sr-dev@lists.sip-router.org">sr-dev@lists.sip-router.org</a>
<a class="moz-txt-link-freetext" href="http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev">http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev</a>
</pre>
</blockquote>
<br>
<br>
<div class="moz-signature">-- <br>
<b>Exa-Omicron</b><br>
Patroonsweg 10<br>
3892 DB Zeewolde<br>
Tel.: 088-OMICRON (66 427 66)<br>
<a class="moz-txt-link-freetext" href="http://www.exa-omicron.nl">http://www.exa-omicron.nl</a></div>
</body>
</html>