Forum OpenACS Q&A: "insert a duplicate key into unique index referer_log_pkey" error

AOLServer 3.2
PostgreSQL 7.0.3
OpenACS 3.2.4
Solaris 2.6

I can't seem to track down the following errors, which I believe
occur occasionally when people log in.  I haven't noticed any
problems in functionality, but the error keeps coming.  I've also
included the surrounding log entries for context:

<br>[08/Jan/2001:09:40:37][7988.1377][-conn188-] Notice: Querying '
        select user_id, token, secure_token,
              last_ip, last_hit from sec_sessions
        where session_id = 85;'
<br>[08/Jan/2001:09:40:37][7988.1377][-conn188-] Notice: dbinit: sql
(localhost::aperture-acs): '
        select user_id, token, secure_token,
              last_ip, last_hit from sec_sessions
        where session_id = 85
    '
<br>[08/Jan/2001:09:40:38][7988.1377][-conn188-] Notice:
Querying 'select * from referer_log_glob_patterns;'
<br>[08/Jan/2001:09:40:38][7988.1377][-conn188-] Notice: dbinit: sql
(localhost::aperture-acs): 'select * from referer_log_glob_patterns
'
<br>[08/Jan/2001:09:40:38][7988.1377][-conn188-] Notice:
Querying 'update referer_log set click_count = click_count + 1
where local_url = '/register/index.tcl'
and foreign_url = 'http://aperture.scient.com:8000/register/index.tcl?
return_url=%2fdeliv%2freco%2flayout%2ehtml%3f'
and trunc(entry_date) = trunc(sysdate());'
<br>[08/Jan/2001:09:40:38][7988.1378][-conn189-] Notice:
Querying 'select * from referer_log_glob_patterns;'
<br>[08/Jan/2001:09:40:38][7988.1378][-conn189-] Notice: dbinit: sql
(localhost::aperture-acs): 'select * from referer_log_glob_patterns
'
<br>[08/Jan/2001:09:40:38][7988.1378][-conn189-] Notice:
Querying 'update referer_log set click_count = click_count + 1
where local_url = '/register/index.tcl'
and foreign_url = 'http://aperture.scient.com:8000/register/index.tcl?
return_url=%2fdeliv%2freco%2flayout%2ehtml%3f'
and trunc(entry_date) = trunc(sysdate());'
<br>[08/Jan/2001:09:40:38][7988.1378][-conn189-] Notice: dbinit: sql
(localhost::aperture-acs): 'update referer_log set click_count = cl
ick_count + 1
where local_url = '/register/index.tcl'
and foreign_url = 'http://aperture.scient.com:8000/register/index.tcl?
return_url=%2fdeliv%2freco%2flayout%2ehtml%3f'
and trunc(entry_date) = trunc(sysdate())'
<br>[08/Jan/2001:09:40:38][7988.1378][-conn189-] Notice:
Querying 'insert into referer_log (local_url, foreign_url,
entry_date, click_c
ount)
select '/register/index.tcl', 'http://aperture.scient.com:8000/registe
r/index.tcl?return_url=%2fdeliv%2freco%2flayout%2ehtml%3f', t
runc(sysdate()), 1
from dual
where 0 = (select count(*)
          from referer_log
          where local_url = '/register/index.tcl'
          and foreign_url
= 'http://aperture.scient.com:8000/register/index.tcl?return_url=%
2fdeliv%2freco%2flayout%2ehtml%3f'
          and trunc(entry_date) = trunc(sysdate()));'
<br>[08/Jan/2001:09:40:38][7988.1377][-conn188-] Notice: dbinit: sql
(localhost::aperture-acs): 'update referer_log set click_count = cl
ick_count + 1
where local_url = '/register/index.tcl'
and foreign_url = 'http://aperture.scient.com:8000/register/index.tcl?
return_url=%2fdeliv%2freco%2flayout%2ehtml%3f'
and trunc(entry_date) = trunc(sysdate())'
<br>[08/Jan/2001:09:40:38][7988.1377][-conn188-] Notice:
Querying 'insert into referer_log (local_url, foreign_url,
entry_date, click_c
ount)
select '/register/index.tcl', 'http://aperture.scient.com:8000/registe
r/index.tcl?return_url=%2fdeliv%2freco%2flayout%2ehtml%3f', t
runc(sysdate()), 1
from dual
where 0 = (select count(*)
          from referer_log
          where local_url = '/register/index.tcl'
          and foreign_url
= 'http://aperture.scient.com:8000/register/index.tcl?return_url=%
2fdeliv%2freco%2flayout%2ehtml%3f'
          and trunc(entry_date) = trunc(sysdate()));'
<br>[08/Jan/2001:09:40:38][7988.1378][-conn189-] Notice: dbinit: sql
(localhost::aperture-acs): 'insert into referer_log (local_url, for
eign_url, entry_date, click_count)
select '/register/index.tcl', 'http://aperture.scient.com:8000/registe
r/index.tcl?return_url=%2fdeliv%2freco%2flayout%2ehtml%3f', t
runc(sysdate()), 1
from dual
where 0 = (select count(*)
          from referer_log
          where local_url = '/register/index.tcl'
          and foreign_url
= 'http://aperture.scient.com:8000/register/index.tcl?return_url=%
2fdeliv%2freco%2flayout%2ehtml%3f'
          and trunc(entry_date) = trunc(sysdate()))'
<br>[08/Jan/2001:09:40:38][7988.1377][-conn188-] Error: Ns_PgExec:
result status: 7 message: ERROR:  Cannot insert a duplicate key into
unique index referer_log_pkey

<br>[08/Jan/2001:09:40:38][7988.1377][-conn188-] Error: dbinit: error
(localhost::aperture-acs,ERROR:  Cannot insert a duplicate key int
o unique index referer_log_pkey
): 'insert into referer_log (local_url, foreign_url, entry_date,
click_count)
select '/register/index.tcl', 'http://aperture.scient.com:8000/registe
r/index.tcl?return_url=%2fdeliv%2freco%2flayout%2ehtml%3f', t
runc(sysdate()), 1
from dual
where 0 = (select count(*)
          from referer_log
          where local_url = '/register/index.tcl'
          and foreign_url
= 'http://aperture.scient.com:8000/register/index.tcl?return_url=%
2fdeliv%2freco%2flayout%2ehtml%3f'
          and trunc(entry_date) = trunc(sysdate()))'
<br>[08/Jan/2001:09:40:38][7988.1377][-conn188-] Error: Filter
ad_referer_filter returned error #1: Database operation "dml" failed
<brOP
many thanks for any pointers...

That's perhaps the most confusing part.  I'm assuming that the english version of what's happening here is something like: "insert this into referer_log if its not already there".  I've tried cutting and pasting the the inserts and haven't had any problems (assuming that the "INSERT 0 0" that psql responds with is a-ok).  The select statement in the "where 0 = select blah blah" is returning 1 so that the where clause fails.

Ultimately it seems I'm unable to reproduce the error on the command line.

Is there anything else I can do to troubleshoot this one?  This is my first foray into the AOLServer/tcl/ACS/postgre world.

thanks for the help,
+jeff

I'm also getting these errors. Just to clarify, the exact line of SQL that is generating the errors is:

    Error: dbinit: error(localhost::servername,ERROR:  Cannot insert a duplicate key into unique index referer_log_pkey
    ): 'insert into referer_log (local_url, foreign_url, entry_date, click_count)
    select '/demo.tcl', 'http://www.servername.com/', trunc(sysdate()), 1
    from dual
    where 0 = (select count(*) 
               from referer_log
               where local_url = '/demo.tcl'
               and foreign_url = 'http://www.servername.com/'
               and trunc(entry_date) = trunc(sysdate()))'

I can't figure out why this SQL should fail? Is it possible that I have a corrupted database table? I'm running Postgres 7.0.2 under Redhat 7.1.

I've found a similar problem, and i think i've found the reason.

Look at the error i found in my server.log. It tries to register a hit from another machine's bboard page:

[20/Jun/2001:00:03:38][4418.6151][-conn2-] Error: dbinit: error(localhost::test6db,
ERROR:  Cannot insert a duplicate key into unique index referer_log_pkey):
'insert into referer_log (local_url, foreign_url, entry_date, click_count)
select '/documentacion/informes/',
'http://xxx/bboard/q-and-a-fetch-msg.tcl?msg_id=00005l&topic_id=6&topic=proyecto%3a%20b2c', trunc(sysdate()), 1
from dual
where 0 = (select count(*)
       from referer_log
       where local_url = '/documentacion/informes/'
       and foreign_url = 'http://xxx/bboard/q-and-a-fetch-msg.tcl?msg_id=00005l&topic_id=6&topic=Proyecto%3a%20B2C'
       and trunc(entry_date) = trunc(sysdate()))'

Have you seen the problem? It's trying to insert the URL in lowercase, but it's checking that the real URL is not in th DB.

Here you have the code at tcl/ad-referer.tcl:

set insert_sql "insert into referer_log (local_url, foreign_url, entry_date, click_count)
select '[DoubleApos [ns_conn url]]', '[string tolower [DoubleApos $foreign_url]]', trunc(sysdate()), 1
from dual
where 0 = (select count(*)
           from referer_log
           where local_url = '[DoubleApos [ns_conn url]]'
           and foreign_url = '[DoubleApos $foreign_url]'
           and trunc(entry_date) = trunc(sysdate()))"
               ns_db dml $db $insert_sql

I think this is a genuine bug. Should i post a patch in the SDM? (it's not a big change, you only have to change a bit the query:

...
...
where local_url = '[DoubleApos [ns_conn url]]'
           and foreign_url = '[string tolower [DoubleApos $foreign_url]]'
...

I don't know what's the problem in John's case (http://www.servername.com/ is lowercase, but maybe he has changed the URL to post it here), and Jeff's URLs are all lowercase.

I hope that helps.