dbmail-imapd fetch'ing header fields returns empty results

[owldance]

Hi

It seems I can't fetch any existing individual header fields e.g.

. fetch 1 body[header.fields (date)]
* 1 FETCH (BODY[HEADER.FIELDS (date)] {2}

)
. OK fetch completed

This also doesn't work

. fetch 1 body.peek[header.fields (date)]

Whereas these all returns the expected results

. fetch 1 body[]
. fetch 1 body[header]
. fetch 1 body[text]

DBMail 3.4.1 as systemd service on ubuntu 22.04.1 with PostgreSQL 14.11. Connecting via telnet on port 143

[alan-hicks]

Thanks for finding this bug, it's an off by one error.
fetch 1 body[header.fields (date subject)]
returns date
fetch 1 body[header.fields (date subject foo)]
returns date and subject

[owldance]

I can't replicate that on my installation.

. fetch 1 body[header.fields (date subject)]
* 1 FETCH (BODY[HEADER.FIELDS (date subject)] {2}

)
. OK fetch completed
. fetch 1 body[header.fields (date subject foo)]
* 1 FETCH (BODY[HEADER.FIELDS (date subject foo)] {2}

)
. OK fetch completed

[alan-hicks]

Could you try it with a uid
fetch {uid} body[header.fields (date subject foo)]

[alan-hicks]

Hopefully this fixes your issue

[owldance]

Sorry, it doesn't seem to work. I cloned your repo, stopped the service, then ./compile, make, sudo make install, started the service again.

This first fetch also didn´t work before your update

. fetch 1:10 (uid, rfc822.size, flags)
* 1 FETCH (FLAGS (\Seen))
* 2 FETCH (FLAGS (\Seen))
. OK fetch completed
. fetch 1 body[header.fields (date subject)]
* 1 FETCH (BODY[HEADER.FIELDS (date subject)] {2}

)
. OK fetch completed
. fetch 1 body[header.fields (date subject foo)]
* 1 FETCH (BODY[HEADER.FIELDS (date subject foo)] {2}

)
. OK fetch completed

[alan-hicks]

Do you have those headers in the dbmail_headername table?

Can you show a detailed log

My successful log follows, it show the IDs from the dbmail_headername table
_fetch_headers(+825): [headername ids 0,2,5,12]
with 2 = date, 5 = from and 12 = subject, yours may be different

Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[imap] _fetch_headers(+731): [0x7417fa0] init bodyfetch->headers
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[imap] _fetch_headers(+757): [0x7417fa0] for 5352948 [(date from subject)]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[imap] _fetch_headers(+778): [0x7417fa0] prefetch 5352948:5352948 ceiling 0 [(date from subject)]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_get(+330): [0x71c3ea0] connection from pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_query(+430): [0x71c3ea0] [select id from dbmail_headername where headername='date']
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] log_query_time(+374): last query took [0] seconds
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_close(+358): [0x71c3ea0] connection to pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_get(+330): [0x71c3ea0] connection from pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_query(+430): [0x71c3ea0] [select id from dbmail_headername where headername='from']
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] log_query_time(+374): last query took [0] seconds
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_close(+358): [0x71c3ea0] connection to pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_get(+330): [0x71c3ea0] connection from pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_query(+430): [0x71c3ea0] [select id from dbmail_headername where headername='subject']
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] log_query_time(+374): last query took [0] seconds
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_close(+358): [0x71c3ea0] connection to pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[imap] _fetch_headers(+825): [headername ids 0,2,5,12]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_get(+330): [0x71c3ea0] connection from pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_query(+430): [0x71c3ea0] [SELECT m.message_idnr, n.headername, v.headervalue, CASE WHEN n.headername='date' THEN 0 WHEN n.headername='from' THEN 1 WHEN n.headername='subject' THEN 2 ELSE 3 END AS seq FROM dbmail_header h LEFT JOIN dbmail_messages m ON h.physmessage_id=m.physmessage_id LEFT JOIN dbmail_headername n ON h.headername_id=n.id LEFT JOIN dbmail_headervalue v ON h.headervalue_id=v.id WHERE h.headername_id IN (0,2,5,12) AND m.mailbox_idnr = 1 AND m.message_idnr = 5352948 AND status < 2 GROUP By m.message_idnr, n.headername, v.headervalue ORDER BY m.message_idnr, seq]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] log_query_time(+374): last query took [0] seconds
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[iconv] dbmail_iconv_once(+64): key "ENCODING" section "DBMAIL" var ic->db_charset value [utf8]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[iconv] dbmail_iconv_once(+65): key "DEFAULT_MSG_ENCODING" section "DBMAIL" var ic->msg_charset value [utf8]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[iconv] dbmail_iconv_once(+73): Initialize DB encoding surface [UTF-8..utf8]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[iconv] dbmail_iconv_once(+78): Initialize DB decoding surface [utf8..UTF-8]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[iconv] dbmail_iconv_once(+83): Initialize default MSG decoding surface [utf8..UTF-8]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_close(+358): [0x71c3ea0] connection to pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Debug:[imap] _send_headers(+684): [0x7417fa0] [(date from subject)] [Date: Sat, 16 Mar 2024 23:22:57 -0000
From: alan@example.fom
Subject: Test email
]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_get(+330): [0x71c3ea0] connection from pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_query(+430): [0x71c3ea0] [SELECT seen_flag FROM dbmail_messages WHERE message_idnr=5352948 AND status < 2]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] log_query_time(+374): last query took [0] seconds
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7416250] Database:[db] db_con_close(+358): [0x71c3ea0] connection to pool
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7082b30] Debug:[clientbase] ci_write(+382): [0x7699040] S > [306/306:* 15165 FETCH (FLAGS (\Seen) UID 5352948 BODY[HEADER.FIELDS (date from subject)] {215}
Date: Sat, 16 Mar 2024 23:22:57 -0000
From: alan@example.com
Subject: Test email

)
]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7082b30] Debug:[imap] _ic_cb_leave(+726): handling imap session [0x7417fa0] client_state []
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7082b30] Debug:[clientbase] ci_uncork(+211): [0x7699040] [0] [1], [4000]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7082b30] Debug:[imap] imap_handle_exit(+465): [0x7417fa0] state [3] command_status [1] [FETCH] returned with status [0]
Mar 19 13:24:01 test.p-o.co.uk dbmail-imapd[42577]: [0x7082b30] Debug:[clientbase] ci_write(+382): [0x7699040] S > [28/28:a03 OK UID FETCH completed
]

[owldance]

The dbmail_headername table is completely empty.

dbmail=> select * from dbmail_headername;
 id | headername 
----+------------
(0 rows)

I assume no need for a log then.

[alan-hicks]

Ah, if you set header_cache_readonly = no then deliver a few emails they will populate that table, then set it to yes to stop the table filling up. I've got a task for tomorrow to automatically pre-populate that table.

[owldance]

I have populated the dbmail_headername table with this pgsql script:

populate_dbmail_headername.tar.gz

Unfortunately nothing changed, I still can't fetch fields.

[alan-hicks]

They need to be lower case :(
I've just merged #269 to check and add them if they're not there.

[owldance]

Thank you. Lowercase certainly solved that part of the problem.

The problem that remains is this:

. OK fetch completed
. fetch 1:1 (uid, rfc822.size, flags)
* 1 FETCH (FLAGS (\Seen))
. OK fetch completed
. fetch 1:1 (uid, rfc822.size)
* 1 FETCH (RFC822.SIZE 497)
. OK fetch completed
. fetch 1:1 (uid)
* 1 FETCH (UID 4)
. OK fetch completed
. fetch 1:1 (rfc822.size)
* 1 FETCH (RFC822.SIZE 497)
. OK fetch completed
. fetch 1:1 (flags)
* 1 FETCH (FLAGS (\Seen))
. OK fetch completed

On the first fetch, I would have expected reply * 1 FETCH (UID 4 RFC822.SIZE 497 FLAGS (\Seen)), perhaps another off-by-one error?

[alan-hicks]

There are no comma separators
fetch 1:1 (uid, rfc822.size, flags) should be fetch 1:1 (uid rfc822.size flags)

[owldance]

Thank you once again. It works. I noticed response order does not match fetch request order. I don´t know what the RFC says, perhaps it's OK.

. fetch 1:1 (uid rfc822.size flags)
* 1 FETCH (RFC822.SIZE 497 FLAGS (\Seen) UID 4)
. OK fetch completed

[alan-hicks]

I can't find anything about order of returned items
https://datatracker.ietf.org/doc/html/rfc9051#name-fetch-command
It may be easier to submit multiple calls to get just the items you need. It's asynchronous and the database has good caching so minimal performance penalty.