nix-super/src/libutil/logging.hh

230 lines
6.1 KiB
C++
Raw Normal View History

#pragma once
#include "types.hh"
2020-05-12 00:52:15 +03:00
#include "error.hh"
2020-07-02 18:04:31 +03:00
#include "config.hh"
#include <nlohmann/json.hpp>
namespace nix {
2017-08-14 16:28:16 +03:00
typedef enum {
actUnknown = 0,
2017-08-14 16:28:16 +03:00
actCopyPath = 100,
2020-04-07 00:43:43 +03:00
actFileTransfer = 101,
actRealise = 102,
actCopyPaths = 103,
2017-08-15 16:31:59 +03:00
actBuilds = 104,
actBuild = 105,
actOptimiseStore = 106,
actVerifyPaths = 107,
actSubstitute = 108,
actQueryPathInfo = 109,
Add a post-build-hook Passing `--post-build-hook /foo/bar` to a nix-* command will cause `/foo/bar` to be executed after each build with the following environment variables set: DRV_PATH=/nix/store/drv-that-has-been-built.drv OUT_PATHS=/nix/store/...build /nix/store/...build-bin /nix/store/...build-dev This can be useful in particular to upload all the builded artifacts to the cache (including the ones that don't appear in the runtime closure of the final derivation or are built because of IFD). This new feature prints the stderr/stdout output to the `nix-build` and `nix build` client, and the output is printed in a Nix 2 compatible format: [nix]$ ./inst/bin/nix-build ./test.nix these derivations will be built: /nix/store/ishzj9ni17xq4hgrjvlyjkfvm00b0ch9-my-example-derivation.drv building '/nix/store/ishzj9ni17xq4hgrjvlyjkfvm00b0ch9-my-example-derivation.drv'... hello! bye! running post-build-hook '/home/grahamc/projects/github.com/NixOS/nix/post-hook.sh'... post-build-hook: + sleep 1 post-build-hook: + echo 'Signing paths' /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation post-build-hook: Signing paths /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation post-build-hook: + sleep 1 post-build-hook: + echo 'Uploading paths' /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation post-build-hook: Uploading paths /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation post-build-hook: + sleep 1 post-build-hook: + printf 'very important stuff' /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation [nix-shell:~/projects/github.com/NixOS/nix]$ ./inst/bin/nix build -L -f ./test.nix my-example-derivation> hello! my-example-derivation> bye! my-example-derivation (post)> + sleep 1 my-example-derivation (post)> + echo 'Signing paths' /nix/store/c263gzj2kb2609mz8wrbmh53l14wzmfs-my-example-derivation my-example-derivation (post)> Signing paths /nix/store/c263gzj2kb2609mz8wrbmh53l14wzmfs-my-example-derivation my-example-derivation (post)> + sleep 1 my-example-derivation (post)> + echo 'Uploading paths' /nix/store/c263gzj2kb2609mz8wrbmh53l14wzmfs-my-example-derivation my-example-derivation (post)> Uploading paths /nix/store/c263gzj2kb2609mz8wrbmh53l14wzmfs-my-example-derivation my-example-derivation (post)> + sleep 1 my-example-derivation (post)> + printf 'very important stuff' [1 built, 0.0 MiB DL] Co-authored-by: Graham Christensen <graham@grahamc.com> Co-authored-by: Eelco Dolstra <edolstra@gmail.com>
2019-07-11 21:23:03 +03:00
actPostBuildHook = 110,
actBuildWaiting = 111,
2017-08-14 16:28:16 +03:00
} ActivityType;
typedef enum {
resFileLinked = 100,
resBuildLogLine = 101,
resUntrustedPath = 102,
resCorruptedPath = 103,
resSetPhase = 104,
2017-08-25 22:26:37 +03:00
resProgress = 105,
2017-08-28 15:30:35 +03:00
resSetExpected = 106,
Add a post-build-hook Passing `--post-build-hook /foo/bar` to a nix-* command will cause `/foo/bar` to be executed after each build with the following environment variables set: DRV_PATH=/nix/store/drv-that-has-been-built.drv OUT_PATHS=/nix/store/...build /nix/store/...build-bin /nix/store/...build-dev This can be useful in particular to upload all the builded artifacts to the cache (including the ones that don't appear in the runtime closure of the final derivation or are built because of IFD). This new feature prints the stderr/stdout output to the `nix-build` and `nix build` client, and the output is printed in a Nix 2 compatible format: [nix]$ ./inst/bin/nix-build ./test.nix these derivations will be built: /nix/store/ishzj9ni17xq4hgrjvlyjkfvm00b0ch9-my-example-derivation.drv building '/nix/store/ishzj9ni17xq4hgrjvlyjkfvm00b0ch9-my-example-derivation.drv'... hello! bye! running post-build-hook '/home/grahamc/projects/github.com/NixOS/nix/post-hook.sh'... post-build-hook: + sleep 1 post-build-hook: + echo 'Signing paths' /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation post-build-hook: Signing paths /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation post-build-hook: + sleep 1 post-build-hook: + echo 'Uploading paths' /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation post-build-hook: Uploading paths /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation post-build-hook: + sleep 1 post-build-hook: + printf 'very important stuff' /nix/store/qr213vjmibrqwnyp5fw678y7whbkqyny-my-example-derivation [nix-shell:~/projects/github.com/NixOS/nix]$ ./inst/bin/nix build -L -f ./test.nix my-example-derivation> hello! my-example-derivation> bye! my-example-derivation (post)> + sleep 1 my-example-derivation (post)> + echo 'Signing paths' /nix/store/c263gzj2kb2609mz8wrbmh53l14wzmfs-my-example-derivation my-example-derivation (post)> Signing paths /nix/store/c263gzj2kb2609mz8wrbmh53l14wzmfs-my-example-derivation my-example-derivation (post)> + sleep 1 my-example-derivation (post)> + echo 'Uploading paths' /nix/store/c263gzj2kb2609mz8wrbmh53l14wzmfs-my-example-derivation my-example-derivation (post)> Uploading paths /nix/store/c263gzj2kb2609mz8wrbmh53l14wzmfs-my-example-derivation my-example-derivation (post)> + sleep 1 my-example-derivation (post)> + printf 'very important stuff' [1 built, 0.0 MiB DL] Co-authored-by: Graham Christensen <graham@grahamc.com> Co-authored-by: Eelco Dolstra <edolstra@gmail.com>
2019-07-11 21:23:03 +03:00
resPostBuildLogLine = 107,
} ResultType;
2017-08-16 17:38:23 +03:00
typedef uint64_t ActivityId;
2020-07-02 18:04:31 +03:00
struct LoggerSettings : Config
{
Setting<bool> showTrace{
this, false, "show-trace",
R"(
Whether Nix should print out a stack trace in case of Nix
expression evaluation errors.
)"};
2020-07-02 18:04:31 +03:00
};
extern LoggerSettings loggerSettings;
class Logger
{
friend struct Activity;
public:
struct Field
{
// FIXME: use std::variant.
enum { tInt = 0, tString = 1 } type;
uint64_t i = 0;
std::string s;
Field(const std::string & s) : type(tString), s(s) { }
Field(const char * s) : type(tString), s(s) { }
Field(const uint64_t & i) : type(tInt), i(i) { }
};
typedef std::vector<Field> Fields;
virtual ~Logger() { }
virtual void stop() { };
// Whether the logger prints the whole build log
virtual bool isVerbose() { return false; }
virtual void log(Verbosity lvl, const FormatOrString & fs) = 0;
void log(const FormatOrString & fs)
{
log(lvlInfo, fs);
}
virtual void logEI(const ErrorInfo &ei) = 0;
2020-04-29 19:14:32 +03:00
void logEI(Verbosity lvl, ErrorInfo ei)
{
ei.level = lvl;
logEI(ei);
}
2020-04-29 19:14:32 +03:00
2017-04-12 15:53:10 +03:00
virtual void warn(const std::string & msg);
virtual void startActivity(ActivityId act, Verbosity lvl, ActivityType type,
const std::string & s, const Fields & fields, ActivityId parent) { };
2017-08-16 17:38:23 +03:00
virtual void stopActivity(ActivityId act) { };
virtual void result(ActivityId act, ResultType type, const Fields & fields) { };
virtual void writeToStdout(std::string_view s);
template<typename... Args>
inline void cout(const std::string & fs, const Args & ... args)
{
boost::format f(fs);
formatHelper(f, args...);
writeToStdout(f.str());
}
virtual std::optional<char> ask(std::string_view s)
{ return {}; }
2017-08-16 17:38:23 +03:00
};
ActivityId getCurActivity();
void setCurActivity(const ActivityId activityId);
2017-08-16 17:38:23 +03:00
struct Activity
{
Logger & logger;
const ActivityId id;
Activity(Logger & logger, Verbosity lvl, ActivityType type, const std::string & s = "",
const Logger::Fields & fields = {}, ActivityId parent = getCurActivity());
2017-08-16 17:38:23 +03:00
Activity(Logger & logger, ActivityType type,
const Logger::Fields & fields = {}, ActivityId parent = getCurActivity())
: Activity(logger, lvlError, type, "", fields, parent) { };
2017-08-21 13:00:41 +03:00
Activity(const Activity & act) = delete;
~Activity();
2017-08-16 17:38:23 +03:00
void progress(uint64_t done = 0, uint64_t expected = 0, uint64_t running = 0, uint64_t failed = 0) const
2017-08-25 22:26:37 +03:00
{ result(resProgress, done, expected, running, failed); }
2017-08-16 17:38:23 +03:00
void setExpected(ActivityType type2, uint64_t expected) const
2017-08-28 15:30:35 +03:00
{ result(resSetExpected, type2, expected); }
template<typename... Args>
2017-08-25 22:26:37 +03:00
void result(ResultType type, const Args & ... args) const
{
Logger::Fields fields;
nop{(fields.emplace_back(Logger::Field(args)), 1)...};
2017-08-25 22:26:37 +03:00
result(type, fields);
}
void result(ResultType type, const Logger::Fields & fields) const
{
logger.result(id, type, fields);
}
2017-08-16 17:38:23 +03:00
friend class Logger;
};
struct PushActivity
{
const ActivityId prevAct;
PushActivity(ActivityId act) : prevAct(getCurActivity()) { setCurActivity(act); }
~PushActivity() { setCurActivity(prevAct); }
};
extern Logger * logger;
Logger * makeSimpleLogger(bool printBuildLogs = true);
Logger * makeJSONLogger(Logger & prevLogger);
std::optional<nlohmann::json> parseJSONMessage(const std::string & msg);
bool handleJSONLogMessage(nlohmann::json & json,
const Activity & act, std::map<ActivityId, Activity> & activities,
bool trusted);
bool handleJSONLogMessage(const std::string & msg,
const Activity & act, std::map<ActivityId, Activity> & activities,
bool trusted);
extern Verbosity verbosity; /* suppress msgs > this */
2020-06-04 20:53:19 +03:00
/* Print a message with the standard ErrorInfo format.
In general, use these 'log' macros for reporting problems that may require user
intervention or that need more explanation. Use the 'print' macros for more
lightweight status messages. */
#define logErrorInfo(level, errorInfo...) \
do { \
2020-11-09 15:14:11 +02:00
if ((level) <= nix::verbosity) { \
logger->logEI((level), errorInfo); \
2020-06-04 20:53:19 +03:00
} \
} while (0)
#define logError(errorInfo...) logErrorInfo(lvlError, errorInfo)
#define logWarning(errorInfo...) logErrorInfo(lvlWarn, errorInfo)
/* Print a string message if the current log level is at least the specified
level. Note that this has to be implemented as a macro to ensure that the
arguments are evaluated lazily. */
#define printMsgUsing(loggerParam, level, args...) \
do { \
2020-11-27 13:17:07 +02:00
auto __lvl = level; \
if (__lvl <= nix::verbosity) { \
loggerParam->log(__lvl, fmt(args)); \
} \
} while (0)
#define printMsg(level, args...) printMsgUsing(logger, level, args)
#define printError(args...) printMsg(lvlError, args)
#define notice(args...) printMsg(lvlNotice, args)
#define printInfo(args...) printMsg(lvlInfo, args)
#define printTalkative(args...) printMsg(lvlTalkative, args)
#define debug(args...) printMsg(lvlDebug, args)
#define vomit(args...) printMsg(lvlVomit, args)
2020-06-04 20:53:19 +03:00
/* if verbosity >= lvlWarn, print a message with a yellow 'warning:' prefix. */
2017-04-12 15:53:10 +03:00
template<typename... Args>
inline void warn(const std::string & fs, const Args & ... args)
2017-04-12 15:53:10 +03:00
{
boost::format f(fs);
formatHelper(f, args...);
2017-04-12 15:53:10 +03:00
logger->warn(f.str());
}
void warnOnce(bool & haveWarned, const FormatOrString & fs);
void writeToStderr(std::string_view s);
}