Commit 7aa8e4b6 authored by Cyrill Gorcunov's avatar Cyrill Gorcunov

log: log-engine slight redesign

The messages are filtered by their type

    LOG_MSG     - plain messages, they escape any (!) log level
                  filtration and go to stdout
    LOG_ERROR   - error messages
    LOG_WARN    - warning messages
    LOG_INFO    - informative messages
    LOG_DEBUG   - debug messages

By default the LOG_WARN log level is used, thus LOG_INFO
and LOG_DEBUG messages will not appear in output stream.

pr_panic helper was replaced with pr_err, pr_warning
shorthanded to pr_warn and old printk if rather pr_msg
now.

Because we share messages between "show" and "dump" actions,
before the "show" action proceed we need to tune up
log level and set it to LOG_INFO.

Also note that printing of VMA and siginfo now
became LOG_INFO messages, it was not that correct
to print them regardless the log level.
Signed-off-by: 's avatarCyrill Gorcunov <gorcunov@openvz.org>
Acked-by: 's avatarPavel Emelyanov <xemul@parallels.com>
parent 9aa2252c
......@@ -461,7 +461,7 @@ static int dump_task_mappings(pid_t pid, struct list_head *vma_area_list, struct
goto err;
}
} else {
pr_panic("Unknown VMA (pid: %d)\n", pid);
pr_err("Unknown VMA (pid: %d)\n", pid);
goto err;
}
}
......
......@@ -195,7 +195,7 @@ static int collect_shmem(int pid, struct shmem_entry *e)
if ((nr_shmems + 1) * sizeof(struct shmem_info) +
sizeof (struct shmems) >= SHMEMS_SIZE) {
pr_panic("OOM storing shmems\n");
pr_err("OOM storing shmems\n");
return -1;
}
......@@ -253,7 +253,7 @@ static int collect_pipe(int pid, struct pipe_entry *e, int p_fd)
}
if ((nr_pipes + 1) * sizeof(struct pipe_info) >= 4096) {
pr_panic("OOM storing pipes\n");
pr_err("OOM storing pipes\n");
return -1;
}
......@@ -1155,7 +1155,7 @@ static int restore_one_zombie(int pid, int exit_code)
signr = exit_code & 0x7F;
if (!sig_fatal(signr)) {
pr_warning("Exit with non fatal signal ignored\n");
pr_warn("Exit with non fatal signal ignored\n");
signr = SIGABRT;
}
......@@ -1807,7 +1807,7 @@ static void sigreturn_restore(pid_t pid)
task_args->pid = pid;
task_args->fd_core = fd_core;
task_args->fd_self_vmas = fd_self_vmas;
task_args->logfd = get_logfd();
task_args->logfd = log_get_fd();
task_args->sigchld_act = sigchld_act;
task_args->fd_fdinfo = fd_fdinfo;
......
......@@ -341,7 +341,7 @@ int main(int argc, char *argv[])
}
break;
case 'o':
if (init_log(optarg))
if (log_init(optarg))
return -1;
log_inited = 1;
break;
......@@ -373,10 +373,10 @@ int main(int argc, char *argv[])
if (log_level < 0)
log_level = -log_level;
set_loglevel(log_level);
log_set_loglevel(log_level);
if (!log_inited) {
ret = init_log(NULL);
ret = log_init(NULL);
if (ret)
return ret;
}
......@@ -404,6 +404,7 @@ int main(int argc, char *argv[])
ret = cr_restore_tasks(pid, &opts);
break;
case 's':
log_set_loglevel(LOG_INFO);
ret = cr_show(pid, &opts);
break;
default:
......@@ -414,38 +415,38 @@ int main(int argc, char *argv[])
return ret;
usage:
printk("\nUsage:\n");
printk(" %s dump [-c] -p|-t pid [-n ns]\n", argv[0]);
printk(" %s restore -p|-t pid [-n ns]\n", argv[0]);
printk(" %s show [-c] (-p|-t pid)|(-f file)\n", argv[0]);
printk("\nCommands:\n");
printk(" dump checkpoint a process identified by pid\n");
printk(" restore restore a process identified by pid\n");
printk(" show show dump contents of a process identified by pid\n");
printk("\nGeneral parameters:\n");
printk(" -p checkpoint/restore only a single process identified by pid\n");
printk(" -t checkpoint/restore the whole process tree identified by pid\n");
printk(" -f show contents of a checkpoint file\n");
printk(" -c show contents of pages dumped in hexdump format\n");
printk(" -d detach after restore\n");
printk(" -s leave tasks in stopped state after checkpoint instead of killing them\n");
printk(" -n checkpoint/restore namespaces - values must be separated by comma\n");
printk(" supported: uts, ipc\n");
printk("\nAdditional common parameters:\n");
printk(" -D dir save checkpoint files in specified directory\n");
printk(" -v [num] set logging level\n");
printk(" 0 - silent (only error messages)\n");
printk(" 1 - informative (default)\n");
printk(" 2 - debug\n");
printk(" -vv same as -v 1\n");
printk(" -vvv same as -v 2\n");
printk("\n");
pr_msg("\nUsage:\n");
pr_msg(" %s dump [-c] -p|-t pid [-n ns]\n", argv[0]);
pr_msg(" %s restore -p|-t pid [-n ns]\n", argv[0]);
pr_msg(" %s show [-c] (-p|-t pid)|(-f file)\n", argv[0]);
pr_msg("\nCommands:\n");
pr_msg(" dump checkpoint a process identified by pid\n");
pr_msg(" restore restore a process identified by pid\n");
pr_msg(" show show dump contents of a process identified by pid\n");
pr_msg("\nGeneral parameters:\n");
pr_msg(" -p checkpoint/restore only a single process identified by pid\n");
pr_msg(" -t checkpoint/restore the whole process tree identified by pid\n");
pr_msg(" -f show contents of a checkpoint file\n");
pr_msg(" -c show contents of pages dumped in hexdump format\n");
pr_msg(" -d detach after restore\n");
pr_msg(" -s leave tasks in stopped state after checkpoint instead of killing them\n");
pr_msg(" -n checkpoint/restore namespaces - values must be separated by comma\n");
pr_msg(" supported: uts, ipc\n");
pr_msg("\nAdditional common parameters:\n");
pr_msg(" -D dir save checkpoint files in specified directory\n");
pr_msg(" -v [num] set logging level\n");
pr_msg(" 0 - silent (only error messages)\n");
pr_msg(" 1 - informative (default)\n");
pr_msg(" 2 - debug\n");
pr_msg(" -vv same as -v 1\n");
pr_msg(" -vvv same as -v 2\n");
pr_msg("\n");
return -1;
opt_pid_missing:
printk("No pid specified (-t or -p option missing)\n");
pr_msg("No pid specified (-t or -p option missing)\n");
return -1;
}
......@@ -81,7 +81,7 @@ static int collect_fd(int pid, struct fdinfo_entry *e)
nr_fdinfo_list++;
if ((nr_fdinfo_list) * sizeof(struct fdinfo_list_entry) >= 4096) {
pr_panic("OOM storing fdinfo_list_entries\n");
pr_err("OOM storing fdinfo_list_entries\n");
return -1;
}
......@@ -108,7 +108,7 @@ static int collect_fd(int pid, struct fdinfo_entry *e)
}
if ((nr_fdinfo_descs + 1) * sizeof(struct fdinfo_desc) >= 4096) {
pr_panic("OOM storing fdinfo descriptions\n");
pr_err("OOM storing fdinfo descriptions\n");
return -1;
}
......
#ifndef LOG_H__
#define LOG_H__
extern int init_log(const char *name);
extern void fini_log(void);
extern int get_logfd(void);
extern int log_init(const char *output);
extern void log_fini(void);
#define LOG_ERROR (0) /* Errors only */
#define LOG_WARN (1) /* Informative */
#define LOG_DEBUG (2) /* Debug ones */
extern int log_get_fd(void);
extern void set_loglevel(unsigned int level);
extern void printk_level(unsigned int level, const char *format, ...)
extern void log_set_loglevel(unsigned int loglevel);
extern void print_on_level(unsigned int loglevel, const char *format, ...)
__attribute__ ((__format__ (__printf__, 2, 3)));
#define printk(fmt, ...) \
printk_level(LOG_WARN, fmt, ##__VA_ARGS__)
#define LOG_MSG (0) /* Print message regardless of log level */
#define LOG_ERROR (1) /* Errors only, when we're in trouble */
#define LOG_WARN (2) /* Warnings, dazen and confused but trying to continue */
#define LOG_INFO (3) /* Informative, everything is fine */
#define LOG_DEBUG (4) /* Debug only */
#define pr_msg(fmt, ...) \
print_on_level(LOG_MSG, fmt, ##__VA_ARGS__)
#define pr_info(fmt, ...) \
printk_level(LOG_WARN, fmt, ##__VA_ARGS__)
print_on_level(LOG_INFO, fmt, ##__VA_ARGS__)
#define pr_err(fmt, ...) \
printk_level(LOG_ERROR, "Error (%s:%d): " fmt, __FILE__, __LINE__, ##__VA_ARGS__)
#define pr_panic(fmt, ...) \
printk_level(LOG_ERROR, "Panic (%s:%d): " fmt, __FILE__, __LINE__, ##__VA_ARGS__)
print_on_level(LOG_ERROR, "Error (%s:%d): " fmt, __FILE__, __LINE__, ##__VA_ARGS__)
#define pr_warning(fmt, ...) \
printk_level(LOG_WARN, "Warn (%s:%d): " fmt, __FILE__, __LINE__, ##__VA_ARGS__)
#define pr_warn(fmt, ...) \
print_on_level(LOG_WARN, "Warn (%s:%d): " fmt, __FILE__, __LINE__, ##__VA_ARGS__)
#define pr_debug(fmt, ...) \
printk_level(LOG_DEBUG, fmt, ##__VA_ARGS__)
print_on_level(LOG_DEBUG, fmt, ##__VA_ARGS__)
#define pr_perror(fmt, ...) \
pr_err(fmt ": %m\n", ##__VA_ARGS__)
......
......@@ -131,12 +131,12 @@ static inline int read_img_buf(int fd, void *ptr, int size)
#define memzero_p(p) memset(p, 0, sizeof(*p))
#define memzero(p, size) memset(p, 0, size)
extern void printk_siginfo(siginfo_t *siginfo);
extern void pr_info_siginfo(siginfo_t *siginfo);
struct vma_area;
struct list_head;
extern void printk_vma(struct vma_area *vma_area);
extern void pr_info_vma(struct vma_area *vma_area);
#define pr_info_vma_list(head) \
do { \
......@@ -160,9 +160,6 @@ extern void printk_vma(struct vma_area *vma_area);
p__; \
})
#define pr_info_vma(vma_area) printk_vma(vma_area)
#define pr_info_siginfo(siginfo) printk_siginfo(siginfo)
extern int move_img_fd(int *img_fd, int want_fd);
extern int close_safe(int *fd);
......
......@@ -16,7 +16,7 @@ int parse_rtattr(struct rtattr *tb[], int max, struct rtattr *rta, int len)
rta = RTA_NEXT(rta,len);
}
if (len)
pr_warning("Trimmed RTA: len %d, rta_len %d\n", len, rta->rta_len);
pr_warn("Trimmed RTA: len %d, rta_len %d\n", len, rta->rta_len);
return 0;
}
......
......@@ -16,74 +16,90 @@
#include "types.h"
#include "util.h"
/* Note pr_ helpers rely on this descriptor! */
static int logfd = STDERR_FILENO;
#define DEFAULT_LOGLEVEL LOG_WARN
#define DEFAULT_LOGFD STDERR_FILENO
int get_logfd(void)
static unsigned int current_loglevel = DEFAULT_LOGLEVEL;
static int current_logfd = DEFAULT_LOGFD;
int log_get_fd(void)
{
return logfd;
return current_logfd;
}
int init_log(const char *name)
int log_init(const char *output)
{
struct rlimit rlimit;
int fd = STDERR_FILENO;
int new_logfd;
if (getrlimit(RLIMIT_NOFILE, &rlimit)) {
pr_err("can't get rlimit: %m\n");
pr_perror("Can't get rlimit");
return -1;
}
if (name) {
fd = open(name, O_CREAT | O_WRONLY);
if (fd == -1) {
pr_perror("Can't create log file %s", name);
/*
* We might need to transfer this descriptors
* to another process' address space (and file
* descriptors space) so we try to minimize
* potential conflict between descriptors and
* try to reopen them somewhere near a limit.
*
* Still an explicit output file might be
* requested.
*/
new_logfd = rlimit.rlim_cur - 1;
if (output) {
new_logfd = open(output, O_CREAT | O_WRONLY);
if (new_logfd < 0) {
pr_perror("Can't create log file %s", output);
return -1;
}
}
logfd = rlimit.rlim_cur - 1;
if (reopen_fd_as(logfd, fd) < 0) {
pr_err("can't duplicate descriptor %d->%d: %m\n",
fd, logfd);
logfd = STDERR_FILENO;
goto err;
current_logfd = new_logfd;
} else {
if (reopen_fd_as(new_logfd, current_logfd) < 0)
goto err;
current_logfd = new_logfd;
}
return 0;
err:
if (name)
close(fd);
pr_perror("Log engine failure, can't duplicate descriptor");
return -1;
}
void fini_log(void)
void log_fini(void)
{
if (logfd != STDERR_FILENO &&
logfd != STDIN_FILENO &&
logfd != STDOUT_FILENO)
close(logfd);
if (current_logfd > 2)
close_safe(&current_logfd);
logfd = STDERR_FILENO;
current_logfd = DEFAULT_LOGFD;
}
static unsigned int loglevel = LOG_WARN;
void set_loglevel(unsigned int level)
void log_set_loglevel(unsigned int level)
{
if (!level)
loglevel = LOG_ERROR;
current_loglevel = DEFAULT_LOGLEVEL;
else
loglevel = level;
current_loglevel = level;
}
void printk_level(unsigned int level, const char *format, ...)
void print_on_level(unsigned int loglevel, const char *format, ...)
{
va_list params;
if (level <= loglevel) {
va_start(params, format);
vdprintf(get_logfd(), format, params);
va_end(params);
int fd;
if (unlikely(loglevel == LOG_MSG)) {
fd = STDOUT_FILENO;
} else {
if (loglevel > current_loglevel)
return;
fd = current_logfd;
}
va_start(params, format);
vdprintf(fd, format, params);
va_end(params);
}
......@@ -143,12 +143,12 @@ retry_signal:
*/
if (ptrace(PTRACE_SETREGS, pid, NULL, &ctl->regs_orig)) {
pr_panic("Can't set registers (pid: %d)\n", pid);
pr_err("Can't set registers (pid: %d)\n", pid);
goto err;
}
if (ptrace(PTRACE_INTERRUPT, pid, NULL, NULL)) {
pr_panic("Can't interrupt (pid: %d)\n", pid);
pr_err("Can't interrupt (pid: %d)\n", pid);
goto err;
}
......@@ -195,7 +195,7 @@ retry_signal:
* Our code is done.
*/
if (ptrace(PTRACE_INTERRUPT, pid, NULL, NULL)) {
pr_panic("Can't interrupt (pid: %d)\n", pid);
pr_err("Can't interrupt (pid: %d)\n", pid);
goto err;
}
......@@ -264,7 +264,7 @@ static int parasite_execute_by_pid(unsigned long cmd, struct parasite_ctl *ctl,
if (ctl->pid != pid)
if (ptrace(PTRACE_SETREGS, pid, NULL, &regs_orig)) {
pr_panic("Can't restore registers (pid: %d)\n", ctl->pid);
pr_err("Can't restore registers (pid: %d)\n", ctl->pid);
return -1;
}
......@@ -417,7 +417,7 @@ static int parasite_set_logfd(struct parasite_ctl *ctl, pid_t pid)
parasite_status_t args = { };
int ret;
ret = parasite_send_fd(ctl, get_logfd());
ret = parasite_send_fd(ctl, log_get_fd());
if (ret)
return ret;
......@@ -542,7 +542,7 @@ int parasite_dump_pages_seized(struct parasite_ctl *ctl, struct list_head *vma_a
ret = parasite_execute(PARASITE_CMD_DUMPPAGES_INIT, ctl, st, sizeof(*st));
if (ret < 0) {
pr_panic("Dumping pages failed with %li (%li) at %li\n",
pr_err("Dumping pages failed with %li (%li) at %li\n",
parasite_dumppages.status.ret,
parasite_dumppages.status.sys_ret,
parasite_dumppages.status.line);
......@@ -574,7 +574,7 @@ int parasite_dump_pages_seized(struct parasite_ctl *ctl, struct list_head *vma_a
else if (vma_area_is(vma_area, VMA_ANON_SHARED))
parasite_dumppages.fd_type = PG_SHARED;
else {
pr_warning("Unexpected VMA area found\n");
pr_warn("Unexpected VMA area found\n");
continue;
}
......@@ -582,7 +582,7 @@ int parasite_dump_pages_seized(struct parasite_ctl *ctl, struct list_head *vma_a
(parasite_status_t *) &parasite_dumppages,
sizeof(parasite_dumppages));
if (ret) {
pr_panic("Dumping pages failed with %li (%li) at %li\n",
pr_err("Dumping pages failed with %li (%li) at %li\n",
parasite_dumppages.status.ret,
parasite_dumppages.status.sys_ret,
parasite_dumppages.status.line);
......@@ -629,26 +629,26 @@ int parasite_cure_seized(struct parasite_ctl *ctl)
if (ctl->remote_map) {
if (munmap_seized(ctl, (void *)ctl->remote_map, ctl->map_length)) {
pr_panic("munmap_seized failed (pid: %d)\n", ctl->pid);
pr_err("munmap_seized failed (pid: %d)\n", ctl->pid);
ret = -1;
}
}
if (ctl->local_map) {
if (munmap(ctl->local_map, parasite_size)) {
pr_panic("munmap failed (pid: %d)\n", ctl->pid);
pr_err("munmap failed (pid: %d)\n", ctl->pid);
ret = -1;
}
}
if (ptrace_poke_area(ctl->pid, (void *)ctl->code_orig,
(void *)ctl->syscall_ip, sizeof(ctl->code_orig))) {
pr_panic("Can't restore syscall blob (pid: %d)\n", ctl->pid);
pr_err("Can't restore syscall blob (pid: %d)\n", ctl->pid);
ret = -1;
}
if (ptrace(PTRACE_SETREGS, ctl->pid, NULL, &ctl->regs_orig)) {
pr_panic("Can't restore registers (pid: %d)\n", ctl->pid);
pr_err("Can't restore registers (pid: %d)\n", ctl->pid);
ret = -1;
}
......
......@@ -140,11 +140,11 @@ int ptrace_show_area_r(pid_t pid, void *addr, long bytes)
else {
unsigned char *c = (unsigned char *)&v;
for (i = sizeof(v)/sizeof(*c); i > 0; i--)
printk("%02x ", c[i - 1]);
printk(" ");
pr_msg("%02x ", c[i - 1]);
pr_msg(" ");
}
}
printk("\n");
pr_msg("\n");
return 0;
err:
return -2;
......@@ -155,7 +155,7 @@ int ptrace_show_area(pid_t pid, void *addr, long bytes)
unsigned long w, i;
if (bytes & (sizeof(long) - 1))
return -1;
printk("%016lx: ", (unsigned long)addr);
pr_msg("%016lx: ", (unsigned long)addr);
for (w = 0; w < bytes / sizeof(long); w++) {
unsigned long *a = addr;
unsigned long v;
......@@ -165,11 +165,11 @@ int ptrace_show_area(pid_t pid, void *addr, long bytes)
else {
unsigned char *c = (unsigned char *)&v;
for (i = 0; i < sizeof(v)/sizeof(*c); i++)
printk("%02x ", c[i]);
printk(" ");
pr_msg("%02x ", c[i]);
pr_msg(" ");
}
}
printk("\n");
pr_msg("\n");
return 0;
err:
return -2;
......
......@@ -468,8 +468,8 @@ static int unix_collect_one(const struct unix_diag_msg *m,
struct stat st;
if (name[0] != '/') {
pr_warning("Relative bind path '%s' "
"unsupported\n", name);
pr_warn("Relative bind path '%s' "
"unsupported\n", name);
xfree(name);
xfree(d);
return 0;
......
......@@ -45,41 +45,41 @@ void hex_dump(void *addr, unsigned long len)
len = (len + 8) & ~7;
for (i = 0; i < len; i += 8) {
printk("%p: %02x %02x %02x %02x %02x %02x %02x %02x\n",
pr_msg("%p: %02x %02x %02x %02x %02x %02x %02x %02x\n",
&p[i], p[i+0], p[i+1], p[i+2], p[i+3],
p[i+4], p[i+5], p[i+6], p[i+7]);
}
}
void printk_siginfo(siginfo_t *siginfo)
void pr_info_siginfo(siginfo_t *siginfo)
{
printk("si_signo %d si_errno %d si_code %d\n",
siginfo->si_signo, siginfo->si_errno, siginfo->si_code);
pr_info("si_signo %d si_errno %d si_code %d\n",
siginfo->si_signo, siginfo->si_errno, siginfo->si_code);
}
void printk_vma(struct vma_area *vma_area)
void pr_info_vma(struct vma_area *vma_area)
{
if (!vma_area)
return;
printk("s: %16lx e: %16lx l: %4liK p: %8x f: %8x pg: %8lx "
"vf: %s st: %s spc: %s\n",
vma_area->vma.start, vma_area->vma.end,
KBYTES(vma_area_len(vma_area)),
vma_area->vma.prot,
vma_area->vma.flags,
vma_area->vma.pgoff,
vma_area->vm_file_fd < 0 ? "n" : "y",
!vma_area->vma.status ? "--" :
((vma_area->vma.status & VMA_FILE_PRIVATE) ? "FP" :
((vma_area->vma.status & VMA_FILE_SHARED) ? "FS" :
((vma_area->vma.status & VMA_ANON_SHARED) ? "AS" :
((vma_area->vma.status & VMA_ANON_PRIVATE) ? "AP" : "--")))),
!vma_area->vma.status ? "--" :
((vma_area->vma.status & VMA_AREA_STACK) ? "stack" :
((vma_area->vma.status & VMA_AREA_HEAP) ? "heap" :
((vma_area->vma.status & VMA_AREA_VSYSCALL) ? "vsyscall" :
((vma_area->vma.status & VMA_AREA_VDSO) ? "vdso" : "n")))));
pr_info("s: %16lx e: %16lx l: %4liK p: %8x f: %8x pg: %8lx "
"vf: %s st: %s spc: %s\n",
vma_area->vma.start, vma_area->vma.end,
KBYTES(vma_area_len(vma_area)),
vma_area->vma.prot,
vma_area->vma.flags,
vma_area->vma.pgoff,
vma_area->vm_file_fd < 0 ? "n" : "y",
!vma_area->vma.status ? "--" :
((vma_area->vma.status & VMA_FILE_PRIVATE) ? "FP" :
((vma_area->vma.status & VMA_FILE_SHARED) ? "FS" :
((vma_area->vma.status & VMA_ANON_SHARED) ? "AS" :
((vma_area->vma.status & VMA_ANON_PRIVATE) ? "AP" : "--")))),
!vma_area->vma.status ? "--" :
((vma_area->vma.status & VMA_AREA_STACK) ? "stack" :
((vma_area->vma.status & VMA_AREA_HEAP) ? "heap" :
((vma_area->vma.status & VMA_AREA_VSYSCALL) ? "vsyscall" :
((vma_area->vma.status & VMA_AREA_VDSO) ? "vdso" : "n")))));
}
int close_safe(int *fd)
......@@ -108,7 +108,7 @@ int reopen_fd_as_safe(int new_fd, int old_fd, bool allow_reuse_fd)
/*
* Standard descriptors.
*/
pr_warning("fd %d already in use\n", new_fd);
pr_warn("fd %d already in use\n", new_fd);
} else {
pr_err("fd %d already in use\n", new_fd);
return -1;
......@@ -171,7 +171,7 @@ int open_image_ro_nocheck(const char *fmt, int pid)
if (tmp == 0)
tmp = open(path, O_RDONLY);
if (tmp < 0)
pr_warning("Can't open image %s for %d: %m\n", fmt, pid);
pr_warn("Can't open image %s for %d: %m\n", fmt, pid);
return tmp;
}
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment