Backend sent D message without prior T ERROR

Hello,

A am running Postgres on a BSD 4.1 system, and have encountered what seems
to be a communication problem between the backend and the frontend when
making a query on a approximately 35M table. This table has the following
fields and types:

Table = trafficevent
+----------------------------------+----------------------------------+-------+
| Field | Type |Length|
+----------------------------------+----------------------------------+-------+
| host | varchar() | 64
|
| type | varchar() | 14
|
| fac | varchar() | 20
|
| area | varchar() | 20
|
| pri | varchar() | 20
|
| ts | int4 | 4
|
| pid | int4 | 4
|
| gid | int4 | 4
|
| uid | int4 | 4
|
| dom | char() | 4
|
| cmd | varchar() | 64
|
| srcip | varchar() | 20
|
| srchost | varchar() | 40
|
| srcport | int4 | 4
|
| dstip | varchar() | 20
|
| dsthost | varchar() | 40
|
| dstport | int4 | 4
|
| proto | varchar() | 40
|
| service | varchar() |
256 |
| sessid | varchar() | 20
|
| cbytes | int8 | 8
|
| sbytes | int8 | 8
|
| reason | varchar() |
256 |
| cached | int4 | 4
|
| auth | varchar() | 20
|
| uoame | varchar() | 20
|
| rname | varchar() | 20
|
| request | varchar() | 64
|
| rstatus | int4 | 4
|
+----------------------------------+----------------------------------+------+
Index: traff_ts_index

Here is the size of the table:

% ls -l traff_ts_index trafficevent
-rw------- 1 xxx xxx 2408448 Feb 28 16:08 traff_ts_index
-rw------- 1 xxx xxx 37363712 Feb 28 16:24 trafficevent

Here is a count of the rows:

loggerd=> select count(ts) from trafficevent;
count
------
123179
(1 row)

I have an application that is querying this table to get nine of the
fields from each tuple. This application is doing reporting on this
information, and needs to query the entire table, and all its tuples in
order to perform its task. Here is what is coming out of fe-exec.c when
things get out of sync between the backend and the frontend:

(gdb) c
Continuing.
Backend sent D message without prior T
Backend sent D message without prior T
Backend sent D message without prior T
Backend sent D message without prior T
Backend sent D message without prior T
^C
Program received signal SIGINT, Interrupt.
0xa0055411 in _syscall_sys_select ()
(gdb) where
#0 0xa0055411 in _syscall_sys_select ()
#1 0x80535c9 in pqWait ()
#2 0x805005a in PQgetResult ()
#3 0x805020a in PQexec ()
#4 0x804dbc5 in pgsql_lib_gen_query (conn=0x806b000,
query=0x80583a2 "SELECT
ts,srchost,dsthost,srcip,dstip,sbytes,cbytes,service
,sessid FROM trafficevent ORDER BY ts ASC")
at pgsql_lib.c:139
#5 0x80486f0 in main (argc=3, argv=0x804792c) at gen_reports.c:225
#6 0xa0000482 in elf_loader ()

It appears that the frontend is in the select call, waiting for the
backend to return information, and keeps complaining about the D message
without prior T. I have a hunch that the backend is sending all the data,
because of some live tracing with gdb that I did on it while it was
'processing' the SELECT sent in to it from the frontend. I don't think
that the table is corrupted or anything because I am able to perform some
other simple queries. For example, I am able to:

loggerd=> select MIN(ts) from trafficevent;
min
---------
944169413

loggerd=> select * from trafficevent where ts='944169413';
host |type |fac |area |pri |
ts|pid|gid|uid|dom |cm
d | srcip|srchost|srcport|
dstip|dsthost|dstport|proto|servic
e|
sessid|cbytes|sbytes|reason|cached|auth|uname|rname|request|rstat
us
--------------+----------+-----------+------+-----+---------+---+---+---+----+--
-----+--------------+-------+-------+--------------+-------+-------+-----+------
-+-------------------+------+------+------+------+----+-----+-----+-------+-----
--
albertus.a.net|nettraffic|telnetproxy|server|major|944169413|247|247|
0|Atnx|tn
authp|192.168.152.39| | 42311|192.168.151.38| | 23|
|tnauth
p|4055176750718606091| 0| 0| | 0| | | |
|
0
albertus.a.net|nettraffic|telnetproxy|server|major|944169413|247|247|
0|Atnx|tn
authp|192.168.152.39| | 42311|192.168.151.38| | 23|
|tnauth
p|4055176750718606091| 0| 0| | 0| | | |
|
0
albertus.a.net|nettraffic|telnetproxy|server|major|944169413|247|247|
0|Atnx|tn
authp|192.168.152.39| | 42311|192.168.151.38| | 23|
|tnauth
p|4055176750718606091| 0| 0| | 0| | | |
|
0
albertus.a.net|nettraffic|telnetproxy|server|major|944169413|247|247|
0|Atnx|tn
authp|192.168.152.39| | 42311|192.168.151.38| | 23|
|tnauth
p|4055176750718606091| 0| 0| | 0| | | |
|
0
albertus.a.net|nettraffic|telnetproxy|server|major|944169413|247|247|
0|Atnx|tn
authp|192.168.152.39| | 42311|192.168.151.38| | 23|
|tnauth
p|4055176750718606091| 0| 0| | 0| | | |
|
0
albertus.a.net|nettraffic|telnetproxy|server|major|944169413|247|247|
0|Atnx|tn
authp|192.168.152.39| | 42311|192.168.151.38| | 23|
|tnauth
p|4055176750718606091| 0| 0| | 0| | | |
|
0
albertus.a.net|nettraffic|telnetproxy|server|major|944169413|247|247|
0|Atnx|tn
authp|192.168.152.39| | 42311|192.168.151.38| | 23|
|tnauth
p|4055176750718606091| 0| 0| | 0| | | |
|
0

I am using the libpq C interface and am running Postgres 6.5.3 on a BSDI
4.1 system.

I am currently looking into this bug, and was wondering if anyone has any
insight into what is going on. I would welcome any workarounds, or
suggestions you might have as to how to fix this problem. This bug has
surfaced in more than just this table. Several other tables that I have
can cause this problem at various different sizes. This seems to happen
on smaller tables when the query is trying to get more fields from the
table.

I will be filing a bug report in the near future. This is reproduceable
on my system on demand. I can also provide more specific information upon
request. Thanks

_____________________________________________________________________________

Jeff Hatch hatch(at)securecomputing(dot)com 651-628-6273

"In the middle of difficulty lies opportunity." - Albert Einstein

-----------------------------------------------------------------------------