Log queue_time and queue_time_overall exclusive of receive time. Bug 2672
[exim.git] / src / src / spool_out.c
1 /*************************************************
2 *     Exim - an Internet mail transport agent    *
3 *************************************************/
4
5 /* Copyright (c) University of Cambridge 1995 - 2018 */
6 /* Copyright (c) The Exim Maintainers 2020 */
7 /* See the file NOTICE for conditions of use and distribution. */
8
9 /* Functions for writing spool files, and moving them about. */
10
11
12 #include "exim.h"
13
14
15
16 /*************************************************
17 *       Deal with header writing errors          *
18 *************************************************/
19
20 /* This function is called immediately after errors in writing the spool, with
21 errno still set. It creates an error message, depending on the circumstances.
22 If errmsg is NULL, it logs the message and panic-dies. Otherwise errmsg is set
23 to point to the message, and -1 is returned. This function makes the code of
24 spool_write_header() a bit neater.
25
26 Arguments:
27    where      SW_RECEIVING, SW_DELIVERING, or SW_MODIFYING
28    errmsg     where to put the message; NULL => panic-die
29    s          text to add to log string
30    temp_name  name of temp file to unlink
31    f          FILE to close, if not NULL
32
33 Returns:      -1 if errmsg is not NULL; otherwise doesn't return
34 */
35
36 static int
37 spool_write_error(int where, uschar **errmsg, uschar *s, uschar *temp_name,
38   FILE *f)
39 {
40 uschar *msg = where == SW_RECEIVING
41   ? string_sprintf("spool file %s error while receiving from %s: %s", s,
42       sender_fullhost ? sender_fullhost : sender_ident,
43       strerror(errno))
44   : string_sprintf("spool file %s error while %s: %s", s,
45       where == SW_DELIVERING ? "delivering" : "modifying",
46       strerror(errno));
47
48 if (temp_name) Uunlink(temp_name);
49 if (f) (void)fclose(f);
50
51 if (errmsg)
52   *errmsg = msg;
53 else
54   log_write(0, LOG_MAIN|LOG_PANIC_DIE, "%s", msg);
55
56 return -1;
57 }
58
59
60
61 /*************************************************
62 *            Open file under temporary name      *
63 *************************************************/
64
65 /* This is used for opening spool files under a temporary name,
66 with a single attempt at deleting if they already exist.
67
68 Argument: temporary name for spool header file
69 Returns:  file descriptor of open file, or < 0 on failure, with errno unchanged
70 */
71
72 int
73 spool_open_temp(uschar *temp_name)
74 {
75 int fd = Uopen(temp_name, O_RDWR|O_CREAT|O_EXCL, SPOOL_MODE);
76
77 /* If the file already exists, something has gone wrong. This process may well
78 have previously created the file if it is delivering more than one address, but
79 it should have renamed it almost immediately. A file could, however, be left
80 around as a result of a system crash, and by coincidence this process might
81 have the same pid. We therefore have one go at unlinking it before giving up.
82 */
83
84 if (fd < 0 && errno == EEXIST)
85   {
86   DEBUG(D_any) debug_printf("%s exists: unlinking\n", temp_name);
87   Uunlink(temp_name);
88   fd = Uopen(temp_name, O_RDWR|O_CREAT|O_EXCL, SPOOL_MODE);
89   }
90
91 /* If the file has been opened, make sure the file's group is the Exim gid, and
92 double-check the mode because the group setting doesn't always get set
93 automatically. */
94
95 if (fd >= 0)
96   if (exim_fchown(fd, exim_uid, exim_gid, temp_name) || fchmod(fd, SPOOL_MODE))
97     {
98     DEBUG(D_any) debug_printf("failed setting perms on %s\n", temp_name);
99     (void) close(fd); fd = -1;
100     Uunlink(temp_name);
101     }
102
103 return fd;
104 }
105
106
107
108 static void
109 spool_var_write(FILE * fp, const uschar * name, const uschar * val)
110 {
111 if (is_tainted(val)) putc('-', fp);
112 fprintf(fp, "-%s %s\n", name, val);
113 }
114
115 /*************************************************
116 *          Write the header spool file           *
117 *************************************************/
118
119 /* Returns the size of the file for success; zero for failure. The file is
120 written under a temporary name, and then renamed. It's done this way so that it
121 works with re-writing the file on message deferral as well as for the initial
122 write. Whenever this function is called, the data file for the message should
123 be open and locked, thus preventing any other exim process from working on this
124 message.
125
126 Argument:
127   id      the message id
128   where   SW_RECEIVING, SW_DELIVERING, or SW_MODIFYING
129   errmsg  where to put an error message; if NULL, panic-die on error
130
131 Returns:  the size of the header texts on success;
132           negative on writing failure, unless errmsg == NULL
133 */
134
135 int
136 spool_write_header(uschar *id, int where, uschar **errmsg)
137 {
138 int fd;
139 int size_correction;
140 FILE * fp;
141 struct stat statbuf;
142 uschar * tname;
143 uschar * fname;
144
145 tname = spool_fname(US"input", message_subdir, US"hdr.", message_id);
146
147 if ((fd = spool_open_temp(tname)) < 0)
148   return spool_write_error(where, errmsg, US"open", NULL, NULL);
149 fp = fdopen(fd, "wb");
150 DEBUG(D_receive|D_deliver) debug_printf("Writing spool header file: %s\n", tname);
151
152 /* We now have an open file to which the header data is to be written. Start
153 with the file's leaf name, to make the file self-identifying. Continue with the
154 identity of the submitting user, followed by the sender's address. The sender's
155 address is enclosed in <> because it might be the null address. Then write the
156 received time and the number of warning messages that have been sent. */
157
158 fprintf(fp, "%s-H\n", message_id);
159 fprintf(fp, "%.63s %ld %ld\n", originator_login, (long int)originator_uid,
160   (long int)originator_gid);
161 fprintf(fp, "<%s>\n", sender_address);
162 fprintf(fp, "%d %d\n", (int)received_time.tv_sec, warning_count);
163
164 fprintf(fp, "-received_time_usec .%06d\n", (int)received_time.tv_usec);
165 fprintf(fp, "-received_time_complete %d.%06d\n",
166   (int)received_time_complete.tv_sec, (int)received_time_complete.tv_usec);
167
168 /* If there is information about a sending host, remember it. The HELO
169 data can be set for local SMTP as well as remote. */
170
171 if (sender_helo_name) spool_var_write(fp, US"helo_name", sender_helo_name);
172
173 if (sender_host_address)
174   {
175   if (is_tainted(sender_host_address)) putc('-', fp);
176   fprintf(fp, "-host_address %s.%d\n", sender_host_address, sender_host_port);
177   if (sender_host_name)
178     spool_var_write(fp, US"host_name", sender_host_name);
179   }
180 if (sender_host_authenticated)
181   spool_var_write(fp, US"host_auth", sender_host_authenticated);
182 if (sender_host_auth_pubname)
183   spool_var_write(fp, US"host_auth_pubname", sender_host_auth_pubname);
184
185 /* Also about the interface a message came in on */
186
187 if (interface_address)
188   {
189   if (is_tainted(interface_address)) putc('-', fp);
190   fprintf(fp, "-interface_address %s.%d\n", interface_address, interface_port);
191   }
192
193 if (smtp_active_hostname != primary_hostname)
194   spool_var_write(fp, US"active_hostname", smtp_active_hostname);
195
196 /* Likewise for any ident information; for local messages this is
197 likely to be the same as originator_login, but will be different if
198 the originator was root, forcing a different ident. */
199
200 if (sender_ident)
201   spool_var_write(fp, US"ident", sender_ident);
202
203 /* Ditto for the received protocol */
204
205 if (received_protocol)
206   spool_var_write(fp, US"received_protocol", received_protocol);
207
208 /* Preserve any ACL variables that are set. */
209
210 tree_walk(acl_var_c, &acl_var_write, fp);
211 tree_walk(acl_var_m, &acl_var_write, fp);
212
213 /* Now any other data that needs to be remembered. */
214
215 if (f.spool_file_wireformat)
216   fprintf(fp, "-spool_file_wireformat\n");
217 else
218   fprintf(fp, "-body_linecount %d\n", body_linecount);
219 fprintf(fp, "-max_received_linelength %d\n", max_received_linelength);
220
221 if (body_zerocount > 0) fprintf(fp, "-body_zerocount %d\n", body_zerocount);
222
223 if (authenticated_id)
224   spool_var_write(fp, US"auth_id", authenticated_id);
225 if (authenticated_sender)
226   spool_var_write(fp, US"auth_sender", authenticated_sender);
227
228 if (f.allow_unqualified_recipient) fprintf(fp, "-allow_unqualified_recipient\n");
229 if (f.allow_unqualified_sender) fprintf(fp, "-allow_unqualified_sender\n");
230 if (f.deliver_firsttime) fprintf(fp, "-deliver_firsttime\n");
231 if (f.deliver_freeze) fprintf(fp, "-frozen " TIME_T_FMT "\n", deliver_frozen_at);
232 if (f.dont_deliver) fprintf(fp, "-N\n");
233 if (host_lookup_deferred) fprintf(fp, "-host_lookup_deferred\n");
234 if (host_lookup_failed) fprintf(fp, "-host_lookup_failed\n");
235 if (f.sender_local) fprintf(fp, "-local\n");
236 if (f.local_error_message) fprintf(fp, "-localerror\n");
237 #ifdef HAVE_LOCAL_SCAN
238 if (local_scan_data) spool_var_write(fp, US"local_scan", local_scan_data);
239 #endif
240 #ifdef WITH_CONTENT_SCAN
241 if (spam_bar)       spool_var_write(fp, US"spam_bar",       spam_bar);
242 if (spam_score)     spool_var_write(fp, US"spam_score",     spam_score);
243 if (spam_score_int) spool_var_write(fp, US"spam_score_int", spam_score_int);
244 #endif
245 if (f.deliver_manual_thaw) fprintf(fp, "-manual_thaw\n");
246 if (f.sender_set_untrusted) fprintf(fp, "-sender_set_untrusted\n");
247
248 #ifdef EXPERIMENTAL_BRIGHTMAIL
249 if (bmi_verdicts) spool_var_write(fp, US"bmi_verdicts", bmi_verdicts);
250 #endif
251
252 #ifndef DISABLE_TLS
253 if (tls_in.certificate_verified) fprintf(fp, "-tls_certificate_verified\n");
254 if (tls_in.cipher) spool_var_write(fp, US"tls_cipher", tls_in.cipher);
255 if (tls_in.peercert)
256   {
257   if (tls_export_cert(big_buffer, big_buffer_size, tls_in.peercert))
258     fprintf(fp, "--tls_peercert %s\n", CS big_buffer);
259   }
260 if (tls_in.peerdn)       spool_var_write(fp, US"tls_peerdn", string_printing(tls_in.peerdn));
261 if (tls_in.sni)          spool_var_write(fp, US"tls_sni",    string_printing(tls_in.sni));
262 if (tls_in.ourcert)
263   {
264   if (tls_export_cert(big_buffer, big_buffer_size, tls_in.ourcert))
265     fprintf(fp, "-tls_ourcert %s\n", CS big_buffer);
266   }
267 if (tls_in.ocsp)         fprintf(fp, "-tls_ocsp %d\n",   tls_in.ocsp);
268 # ifndef DISABLE_TLS_RESUME
269 fprintf(fp, "-tls_resumption %c\n", 'A' + tls_in.resumption);
270 # endif
271 if (tls_in.ver) spool_var_write(fp, US"tls_ver", tls_in.ver);
272 #endif
273
274 #ifdef SUPPORT_I18N
275 if (message_smtputf8)
276   {
277   fprintf(fp, "-smtputf8\n");
278   if (message_utf8_downconvert)
279     fprintf(fp, "-utf8_%sdowncvt\n", message_utf8_downconvert < 0 ? "opt" : "");
280   }
281 #endif
282
283 /* Write the dsn flags to the spool header file */
284 /* DEBUG(D_deliver) debug_printf("DSN: Write SPOOL: -dsn_envid %s\n", dsn_envid); */
285 if (dsn_envid) fprintf(fp, "-dsn_envid %s\n", dsn_envid);
286 /* DEBUG(D_deliver) debug_printf("DSN: Write SPOOL: -dsn_ret %d\n", dsn_ret); */
287 if (dsn_ret) fprintf(fp, "-dsn_ret %d\n", dsn_ret);
288
289 /* To complete the envelope, write out the tree of non-recipients, followed by
290 the list of recipients. These won't be disjoint the first time, when no
291 checking has been done. If a recipient is a "one-time" alias, it is followed by
292 a space and its parent address number (pno). */
293
294 tree_write(tree_nonrecipients, fp);
295 fprintf(fp, "%d\n", recipients_count);
296 for (int i = 0; i < recipients_count; i++)
297   {
298   recipient_item *r = recipients_list + i;
299
300   /* DEBUG(D_deliver) debug_printf("DSN: Flags: 0x%x\n", r->dsn_flags); */
301
302   if (r->pno < 0 && !r->errors_to && r->dsn_flags == 0)
303     fprintf(fp, "%s\n", r->address);
304   else
305     {
306     uschar * errors_to = r->errors_to ? r->errors_to : US"";
307     /* for DSN SUPPORT extend exim 4 spool in a compatible way by
308     adding new values upfront and add flag 0x02 */
309     uschar * orcpt = r->orcpt ? r->orcpt : US"";
310
311     fprintf(fp, "%s %s %d,%d %s %d,%d#3\n", r->address, orcpt, Ustrlen(orcpt),
312       r->dsn_flags, errors_to, Ustrlen(errors_to), r->pno);
313     }
314
315     DEBUG(D_deliver) debug_printf("DSN: **** SPOOL_OUT - "
316       "address: <%s> errorsto: <%s> orcpt: <%s> dsn_flags: 0x%x\n",
317       r->address, r->errors_to, r->orcpt, r->dsn_flags);
318   }
319
320 /* Put a blank line before the headers */
321
322 fprintf(fp, "\n");
323
324 /* Save the size of the file so far so we can subtract it from the final length
325 to get the actual size of the headers. */
326
327 fflush(fp);
328 if (fstat(fd, &statbuf))
329   return spool_write_error(where, errmsg, US"fstat", tname, fp);
330 size_correction = statbuf.st_size;
331
332 /* Finally, write out the message's headers. To make it easier to read them
333 in again, precede each one with the count of its length. Make the count fixed
334 length to aid human eyes when debugging and arrange for it not be included in
335 the size. It is followed by a space for normal headers, a flagging letter for
336 various other headers, or an asterisk for old headers that have been rewritten.
337 These are saved as a record for debugging. Don't included them in the message's
338 size. */
339
340 for (header_line * h = header_list; h; h = h->next)
341   {
342   fprintf(fp, "%03d%c %s", h->slen, h->type, h->text);
343   size_correction += 5;
344   if (h->type == '*') size_correction += h->slen;
345   }
346
347 /* Flush and check for any errors while writing */
348
349 if (fflush(fp) != 0 || ferror(fp))
350   return spool_write_error(where, errmsg, US"write", tname, fp);
351
352 /* Force the file's contents to be written to disk. Note that fflush()
353 just pushes it out of C, and fclose() doesn't guarantee to do the write
354 either. That's just the way Unix works... */
355
356 if (EXIMfsync(fileno(fp)) < 0)
357   return spool_write_error(where, errmsg, US"sync", tname, fp);
358
359 /* Get the size of the file, and close it. */
360
361 if (fstat(fd, &statbuf) != 0)
362   return spool_write_error(where, errmsg, US"fstat", tname, NULL);
363 if (fclose(fp) != 0)
364   return spool_write_error(where, errmsg, US"close", tname, NULL);
365
366 /* Rename the file to its correct name, thereby replacing any previous
367 incarnation. */
368
369 fname = spool_fname(US"input", message_subdir, id, US"-H");
370 DEBUG(D_receive|D_deliver) debug_printf("Renaming spool header file: %s\n", fname);
371
372 if (Urename(tname, fname) < 0)
373   return spool_write_error(where, errmsg, US"rename", tname, NULL);
374
375 /* Linux (and maybe other OS?) does not automatically sync a directory after
376 an operation like rename. We therefore have to do it forcibly ourselves in
377 these cases, to make sure the file is actually accessible on disk, as opposed
378 to just the data being accessible from a file in lost+found. Linux also has
379 O_DIRECTORY, for opening a directory.
380
381 However, it turns out that some file systems (some versions of NFS?) do not
382 support directory syncing. It seems safe enough to ignore EINVAL to cope with
383 these cases. One hack on top of another... but that's life. */
384
385 #ifdef NEED_SYNC_DIRECTORY
386
387 tname = spool_fname(US"input", message_subdir, US".", US"");
388
389 # ifndef O_DIRECTORY
390 #  define O_DIRECTORY 0
391 # endif
392
393 if ((fd = Uopen(tname, O_RDONLY|O_DIRECTORY, 0)) < 0)
394   return spool_write_error(where, errmsg, US"directory open", fname, NULL);
395
396 if (EXIMfsync(fd) < 0 && errno != EINVAL)
397   return spool_write_error(where, errmsg, US"directory sync", fname, NULL);
398
399 if (close(fd) < 0)
400   return spool_write_error(where, errmsg, US"directory close", fname, NULL);
401
402 #endif  /* NEED_SYNC_DIRECTORY */
403
404 /* Return the number of characters in the headers, which is the file size, less
405 the preliminary stuff, less the additional count fields on the headers. */
406
407 DEBUG(D_receive) debug_printf("Size of headers = %d\n",
408   (int)(statbuf.st_size - size_correction));
409
410 return statbuf.st_size - size_correction;
411 }
412
413
414 /************************************************
415 *              Make a hard link                 *
416 ************************************************/
417
418 /* Used by spool_move_message() below. Note re the use of sprintf(): the value
419 of spool_directory is checked to ensure that it is less than 200 characters at
420 start-up time.
421
422 Arguments:
423   dir        base directory name
424   dq         destiinationqueue name
425   subdir     subdirectory name
426   id         message id
427   suffix     suffix to add to id
428   from       source directory prefix
429   to         destination directory prefix
430   noentok    if TRUE, absence of file is not an error
431
432 Returns:     TRUE if all went well
433              FALSE, having panic logged if not
434 */
435
436 static BOOL
437 make_link(uschar *dir, uschar * dq, uschar *subdir, uschar *id, uschar *suffix,
438   uschar *from, uschar *to, BOOL noentok)
439 {
440 uschar * fname = spool_fname(string_sprintf("%s%s", from, dir), subdir, id, suffix);
441 uschar * tname = spool_q_fname(string_sprintf("%s%s", to,   dir), dq, subdir, id, suffix);
442 if (Ulink(fname, tname) < 0 && (!noentok || errno != ENOENT))
443   {
444   log_write(0, LOG_MAIN|LOG_PANIC, "link(\"%s\", \"%s\") failed while moving "
445     "message: %s", fname, tname, strerror(errno));
446   return FALSE;
447   }
448 return TRUE;
449 }
450
451
452
453 /************************************************
454 *                Break a link                   *
455 ************************************************/
456
457 /* Used by spool_move_message() below. Note re the use of sprintf(): the value
458 of spool_directory is checked to ensure that it is less than 200 characters at
459 start-up time.
460
461 Arguments:
462   dir        base directory name
463   subdir     subdirectory name
464   id         message id
465   suffix     suffix to add to id
466   from       source directory prefix
467   noentok    if TRUE, absence of file is not an error
468
469 Returns:     TRUE if all went well
470              FALSE, having panic logged if not
471 */
472
473 static BOOL
474 break_link(uschar *dir, uschar *subdir, uschar *id, uschar *suffix, uschar *from,
475   BOOL noentok)
476 {
477 uschar * fname = spool_fname(string_sprintf("%s%s", from, dir), subdir, id, suffix);
478 if (Uunlink(fname) < 0 && (!noentok || errno != ENOENT))
479   {
480   log_write(0, LOG_MAIN|LOG_PANIC, "unlink(\"%s\") failed while moving "
481     "message: %s", fname, strerror(errno));
482   return FALSE;
483   }
484 return TRUE;
485 }
486
487
488
489 /************************************************
490 *            Move message files                 *
491 ************************************************/
492
493 /* Move the files for a message (-H, -D, and msglog) from one directory (or
494 hierarchy) to another. It is assume that there is no -J file in existence when
495 this is done.
496
497 Arguments:
498   id          the id of the message to be delivered
499   subdir      the subdirectory name, or an empty string
500   from        a prefix for "input" or "msglog" for where the message is now
501   to          a prefix for "input" or "msglog" for where the message is to go
502
503 Returns:      TRUE if all is well
504               FALSE if not, with error logged in panic and main logs
505 */
506
507 BOOL
508 spool_move_message(uschar *id, uschar *subdir, uschar *from, uschar *to)
509 {
510 uschar * dest_qname = queue_name_dest ? queue_name_dest : queue_name;
511
512 /* Since we are working within the spool, de-taint the dest queue name */
513 dest_qname = string_copy_taint(dest_qname, FALSE);
514
515 /* Create any output directories that do not exist. */
516
517 (void) directory_make(spool_directory,
518   spool_q_sname(string_sprintf("%sinput", to), dest_qname, subdir),
519   INPUT_DIRECTORY_MODE, TRUE);
520 (void) directory_make(spool_directory,
521   spool_q_sname(string_sprintf("%smsglog", to), dest_qname, subdir),
522   INPUT_DIRECTORY_MODE, TRUE);
523
524 /* Move the message by first creating new hard links for all the files, and
525 then removing the old links. When moving messages onto the main spool, the -H
526 file should be set up last, because that's the one that tells Exim there is a
527 message to be delivered, so we create its new link last and remove its old link
528 first. Programs that look at the alternate directories should follow the same
529 rule of waiting for a -H file before doing anything. When moving messages off
530 the mail spool, the -D file should be open and locked at the time, thus keeping
531 Exim's hands off. */
532
533 if (!make_link(US"msglog", dest_qname, subdir, id, US"", from, to, TRUE) ||
534     !make_link(US"input",  dest_qname, subdir, id, US"-D", from, to, FALSE) ||
535     !make_link(US"input",  dest_qname, subdir, id, US"-H", from, to, FALSE))
536   return FALSE;
537
538 if (!break_link(US"input",  subdir, id, US"-H", from, FALSE) ||
539     !break_link(US"input",  subdir, id, US"-D", from, FALSE) ||
540     !break_link(US"msglog", subdir, id, US"", from, TRUE))
541   return FALSE;
542
543 log_write(0, LOG_MAIN, "moved from %s%s%s%sinput, %smsglog to %s%s%s%sinput, %smsglog",
544    *queue_name?"(":"", *queue_name?queue_name:US"", *queue_name?") ":"",
545    from, from,
546    *dest_qname?"(":"", *dest_qname?dest_qname:US"", *dest_qname?") ":"",
547    to, to);
548
549 return TRUE;
550 }
551
552
553 /* End of spool_out.c */
554 /* vi: aw ai sw=2
555 */