important log messages may be truncated

[grondo]

Not sure where the truncation is occurring, but an important log message resulting from the following flux_log() call was truncated in flux dmesg :

            flux_log (hk->ctx->h,
                      LOG_ERR,
                      "housekeeping: %s (rank %s) from %s will be terminated"
                      " because %s",
                      hosts ? hosts : "?",
                      ranks ? ranks : "?",
                      idf58 (a->id),
                      error.text);

In this case >4000 nodes were affected, and the very long nodelist in hosts caused the log message to get truncated, suppressing the actual important bits of the message that sysadmins were searching for (e.g. the jobid).

[grondo]

This should have been obvious, but the internal flux log implementation has a fixed length (2K) buffer into which the stdlog messages are rendered. Since this includes other data besides just the log message itself, messages will be truncated well below 2K characters.

flux-core/src/common/libflux/flog.h

Line 24 in 2bbe885

#define FLUX_MAX_LOGBUF 2048

flux-core/src/common/libflux/flog.c

Lines 28 to 34 in 2bbe885

	typedef struct {
	char appname[STDLOG_MAX_APPNAME + 1];
	char procid[STDLOG_MAX_PROCID + 1];
	char buf[FLUX_MAX_LOGBUF];
	flux_log_f cb;
	void *cb_arg;
	} logctx_t;

Perhaps this fixed buffer was used to avoid memory allocations when OOM, though I'm guessing there's likely memory allocations if the log data is forwarded via messages or appended to the dmesg buffer?

[garlick]

Yeah I was proabably thinking about the scalability of a million nodes logging towards the root or some other imaginary thinking :-) No harm in detecting truncation and trying again with a malloc maybe? Then at least the common case won't abuse the heap.