2012-08-22 05:09:44 +04:00
/***
This file is part of systemd .
Copyright 2011 Lennart Poettering
systemd is free software ; you can redistribute it and / or modify it
under the terms of the GNU Lesser General Public License as published by
the Free Software Foundation ; either version 2.1 of the License , or
( at your option ) any later version .
systemd is distributed in the hope that it will be useful , but
WITHOUT ANY WARRANTY ; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE . See the GNU
Lesser General Public License for more details .
You should have received a copy of the GNU Lesser General Public License
along with systemd ; If not , see < http : //www.gnu.org/licenses/>.
* * */
# include <fcntl.h>
2015-10-23 19:52:53 +03:00
# include <sys/epoll.h>
2012-08-22 05:09:44 +04:00
# include <sys/mman.h>
2012-08-24 03:46:38 +04:00
# include <sys/socket.h>
2015-10-23 19:52:53 +03:00
# include <unistd.h>
2012-08-22 05:09:44 +04:00
2015-11-17 08:52:45 +03:00
# include "libudev.h"
2015-10-23 19:52:53 +03:00
# include "sd-messages.h"
2012-08-22 05:09:44 +04:00
2015-10-23 19:52:53 +03:00
# include "escape.h"
2015-10-25 15:14:12 +03:00
# include "fd-util.h"
2016-11-07 18:14:59 +03:00
# include "format-util.h"
2015-10-27 03:02:30 +03:00
# include "io-util.h"
2015-10-25 15:14:12 +03:00
# include "journald-kmsg.h"
2012-11-12 20:29:07 +04:00
# include "journald-server.h"
2012-08-22 05:21:03 +04:00
# include "journald-syslog.h"
2015-10-26 18:18:16 +03:00
# include "parse-util.h"
2015-04-10 20:10:00 +03:00
# include "process-util.h"
2015-10-27 03:26:31 +03:00
# include "stdio-util.h"
2015-10-24 23:58:24 +03:00
# include "string-util.h"
2012-08-22 05:09:44 +04:00
void server_forward_kmsg (
Server * s ,
int priority ,
const char * identifier ,
const char * message ,
2014-11-02 23:46:42 +03:00
const struct ucred * ucred ) {
2012-08-22 05:09:44 +04:00
struct iovec iovec [ 5 ] ;
2015-02-03 20:17:00 +03:00
char header_priority [ DECIMAL_STR_MAX ( priority ) + 3 ] ,
2015-01-27 16:00:11 +03:00
header_pid [ sizeof ( " []: " ) - 1 + DECIMAL_STR_MAX ( pid_t ) + 1 ] ;
2012-08-22 05:09:44 +04:00
int n = 0 ;
char * ident_buf = NULL ;
assert ( s ) ;
assert ( priority > = 0 ) ;
assert ( priority < = 999 ) ;
assert ( message ) ;
if ( _unlikely_ ( LOG_PRI ( priority ) > s - > max_level_kmsg ) )
return ;
if ( _unlikely_ ( s - > dev_kmsg_fd < 0 ) )
return ;
/* Never allow messages with kernel facility to be written to
* kmsg , regardless where the data comes from . */
priority = syslog_fixup_facility ( priority ) ;
/* First: priority field */
2015-01-27 16:00:11 +03:00
xsprintf ( header_priority , " <%i> " , priority ) ;
2012-08-22 05:09:44 +04:00
IOVEC_SET_STRING ( iovec [ n + + ] , header_priority ) ;
/* Second: identifier and PID */
if ( ucred ) {
if ( ! identifier ) {
get_process_comm ( ucred - > pid , & ident_buf ) ;
identifier = ident_buf ;
}
2015-01-27 16:00:11 +03:00
xsprintf ( header_pid , " [ " PID_FMT " ]: " , ucred - > pid ) ;
2012-08-22 05:09:44 +04:00
if ( identifier )
IOVEC_SET_STRING ( iovec [ n + + ] , identifier ) ;
IOVEC_SET_STRING ( iovec [ n + + ] , header_pid ) ;
} else if ( identifier ) {
IOVEC_SET_STRING ( iovec [ n + + ] , identifier ) ;
IOVEC_SET_STRING ( iovec [ n + + ] , " : " ) ;
}
/* Fourth: message */
IOVEC_SET_STRING ( iovec [ n + + ] , message ) ;
IOVEC_SET_STRING ( iovec [ n + + ] , " \n " ) ;
if ( writev ( s - > dev_kmsg_fd , iovec , n ) < 0 )
2014-11-28 21:29:59 +03:00
log_debug_errno ( errno , " Failed to write to /dev/kmsg for logging: %m " ) ;
2012-08-22 05:09:44 +04:00
free ( ident_buf ) ;
}
static bool is_us ( const char * pid ) {
pid_t t ;
assert ( pid ) ;
if ( parse_pid ( pid , & t ) < 0 )
return false ;
2017-07-20 17:19:18 +03:00
return t = = getpid_cached ( ) ;
2012-08-22 05:09:44 +04:00
}
2014-11-02 23:46:42 +03:00
static void dev_kmsg_record ( Server * s , const char * p , size_t l ) {
2012-08-22 05:09:44 +04:00
struct iovec iovec [ N_IOVEC_META_FIELDS + 7 + N_IOVEC_KERNEL_FIELDS + 2 + N_IOVEC_UDEV_FIELDS ] ;
char * message = NULL , * syslog_priority = NULL , * syslog_pid = NULL , * syslog_facility = NULL , * syslog_identifier = NULL , * source_time = NULL ;
int priority , r ;
unsigned n = 0 , z = 0 , j ;
2012-10-26 16:55:03 +04:00
unsigned long long usec ;
2012-08-22 05:09:44 +04:00
char * identifier = NULL , * pid = NULL , * e , * f , * k ;
uint64_t serial ;
size_t pl ;
char * kernel_device = NULL ;
assert ( s ) ;
assert ( p ) ;
if ( l < = 0 )
return ;
e = memchr ( p , ' , ' , l ) ;
if ( ! e )
return ;
* e = 0 ;
r = safe_atoi ( p , & priority ) ;
if ( r < 0 | | priority < 0 | | priority > 999 )
return ;
if ( s - > forward_to_kmsg & & ( priority & LOG_FACMASK ) ! = LOG_KERN )
return ;
l - = ( e - p ) + 1 ;
p = e + 1 ;
e = memchr ( p , ' , ' , l ) ;
if ( ! e )
return ;
* e = 0 ;
r = safe_atou64 ( p , & serial ) ;
if ( r < 0 )
return ;
if ( s - > kernel_seqnum ) {
/* We already read this one? */
if ( serial < * s - > kernel_seqnum )
return ;
/* Did we lose any? */
if ( serial > * s - > kernel_seqnum )
tree-wide: add SD_ID128_MAKE_STR, remove LOG_MESSAGE_ID
Embedding sd_id128_t's in constant strings was rather cumbersome. We had
SD_ID128_CONST_STR which returned a const char[], but it had two problems:
- it wasn't possible to statically concatanate this array with a normal string
- gcc wasn't really able to optimize this, and generated code to perform the
"conversion" at runtime.
Because of this, even our own code in coredumpctl wasn't using
SD_ID128_CONST_STR.
Add a new macro to generate a constant string: SD_ID128_MAKE_STR.
It is not as elegant as SD_ID128_CONST_STR, because it requires a repetition
of the numbers, but in practice it is more convenient to use, and allows gcc
to generate smarter code:
$ size .libs/systemd{,-logind,-journald}{.old,}
text data bss dec hex filename
1265204 149564 4808 1419576 15a938 .libs/systemd.old
1260268 149564 4808 1414640 1595f0 .libs/systemd
246805 13852 209 260866 3fb02 .libs/systemd-logind.old
240973 13852 209 255034 3e43a .libs/systemd-logind
146839 4984 34 151857 25131 .libs/systemd-journald.old
146391 4984 34 151409 24f71 .libs/systemd-journald
It is also much easier to check if a certain binary uses a certain MESSAGE_ID:
$ strings .libs/systemd.old|grep MESSAGE_ID
MESSAGE_ID=%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x
MESSAGE_ID=%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x
MESSAGE_ID=%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x
MESSAGE_ID=%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x
$ strings .libs/systemd|grep MESSAGE_ID
MESSAGE_ID=c7a787079b354eaaa9e77b371893cd27
MESSAGE_ID=b07a249cd024414a82dd00cd181378ff
MESSAGE_ID=641257651c1b4ec9a8624d7a40a9e1e7
MESSAGE_ID=de5b426a63be47a7b6ac3eaac82e2f6f
MESSAGE_ID=d34d037fff1847e6ae669a370e694725
MESSAGE_ID=7d4958e842da4a758f6c1cdc7b36dcc5
MESSAGE_ID=1dee0369c7fc4736b7099b38ecb46ee7
MESSAGE_ID=39f53479d3a045ac8e11786248231fbf
MESSAGE_ID=be02cf6855d2428ba40df7e9d022f03d
MESSAGE_ID=7b05ebc668384222baa8881179cfda54
MESSAGE_ID=9d1aaa27d60140bd96365438aad20286
2016-11-06 20:48:23 +03:00
server_driver_message ( s ,
" MESSAGE_ID= " SD_MESSAGE_JOURNAL_MISSED_STR ,
2015-11-08 22:05:55 +03:00
LOG_MESSAGE ( " Missed % " PRIu64 " kernel messages " ,
serial - * s - > kernel_seqnum ) ,
NULL ) ;
2012-08-22 05:09:44 +04:00
/* Make sure we never read this one again. Note that
* we always store the next message serial we expect
* here , simply because this makes handling the first
* message with serial 0 easy . */
* s - > kernel_seqnum = serial + 1 ;
}
l - = ( e - p ) + 1 ;
p = e + 1 ;
f = memchr ( p , ' ; ' , l ) ;
if ( ! f )
return ;
/* Kernel 3.6 has the flags field, kernel 3.5 lacks that */
e = memchr ( p , ' , ' , l ) ;
if ( ! e | | f < e )
e = f ;
* e = 0 ;
2012-10-26 16:55:03 +04:00
r = safe_atollu ( p , & usec ) ;
2012-08-22 05:09:44 +04:00
if ( r < 0 )
return ;
l - = ( f - p ) + 1 ;
p = f + 1 ;
e = memchr ( p , ' \n ' , l ) ;
if ( ! e )
return ;
* e = 0 ;
pl = e - p ;
l - = ( e - p ) + 1 ;
k = e + 1 ;
for ( j = 0 ; l > 0 & & j < N_IOVEC_KERNEL_FIELDS ; j + + ) {
char * m ;
2015-09-08 13:23:18 +03:00
/* Metadata fields attached */
2012-08-22 05:09:44 +04:00
if ( * k ! = ' ' )
break ;
2016-02-23 07:32:04 +03:00
k + + , l - - ;
2012-08-22 05:09:44 +04:00
e = memchr ( k , ' \n ' , l ) ;
if ( ! e )
return ;
* e = 0 ;
2015-04-06 21:11:41 +03:00
if ( cunescape_length_with_prefix ( k , e - k , " _KERNEL_ " , UNESCAPE_RELAX , & m ) < 0 )
2012-08-22 05:09:44 +04:00
break ;
if ( startswith ( m , " _KERNEL_DEVICE= " ) )
kernel_device = m + 15 ;
IOVEC_SET_STRING ( iovec [ n + + ] , m ) ;
z + + ;
l - = ( e - k ) + 1 ;
k = e + 1 ;
}
if ( kernel_device ) {
struct udev_device * ud ;
ud = udev_device_new_from_device_id ( s - > udev , kernel_device ) ;
if ( ud ) {
const char * g ;
struct udev_list_entry * ll ;
char * b ;
g = udev_device_get_devnode ( ud ) ;
if ( g ) {
b = strappend ( " _UDEV_DEVNODE= " , g ) ;
if ( b ) {
IOVEC_SET_STRING ( iovec [ n + + ] , b ) ;
z + + ;
}
}
g = udev_device_get_sysname ( ud ) ;
if ( g ) {
b = strappend ( " _UDEV_SYSNAME= " , g ) ;
if ( b ) {
IOVEC_SET_STRING ( iovec [ n + + ] , b ) ;
z + + ;
}
}
j = 0 ;
ll = udev_device_get_devlinks_list_entry ( ud ) ;
udev_list_entry_foreach ( ll , ll ) {
if ( j > N_IOVEC_UDEV_FIELDS )
break ;
g = udev_list_entry_get_name ( ll ) ;
if ( g ) {
2013-03-31 01:47:48 +04:00
b = strappend ( " _UDEV_DEVLINK= " , g ) ;
if ( b ) {
IOVEC_SET_STRING ( iovec [ n + + ] , b ) ;
z + + ;
}
2012-08-22 05:09:44 +04:00
}
j + + ;
}
udev_device_unref ( ud ) ;
}
}
2012-10-26 16:55:03 +04:00
if ( asprintf ( & source_time , " _SOURCE_MONOTONIC_TIMESTAMP=%llu " , usec ) > = 0 )
2012-08-22 05:09:44 +04:00
IOVEC_SET_STRING ( iovec [ n + + ] , source_time ) ;
IOVEC_SET_STRING ( iovec [ n + + ] , " _TRANSPORT=kernel " ) ;
if ( asprintf ( & syslog_priority , " PRIORITY=%i " , priority & LOG_PRIMASK ) > = 0 )
IOVEC_SET_STRING ( iovec [ n + + ] , syslog_priority ) ;
2014-07-25 16:38:22 +04:00
if ( asprintf ( & syslog_facility , " SYSLOG_FACILITY=%i " , LOG_FAC ( priority ) ) > = 0 )
IOVEC_SET_STRING ( iovec [ n + + ] , syslog_facility ) ;
2012-08-22 05:09:44 +04:00
if ( ( priority & LOG_FACMASK ) = = LOG_KERN )
IOVEC_SET_STRING ( iovec [ n + + ] , " SYSLOG_IDENTIFIER=kernel " ) ;
else {
2012-10-13 13:31:54 +04:00
pl - = syslog_parse_identifier ( ( const char * * ) & p , & identifier , & pid ) ;
2012-08-22 05:09:44 +04:00
/* Avoid any messages we generated ourselves via
* log_info ( ) and friends . */
if ( pid & & is_us ( pid ) )
goto finish ;
if ( identifier ) {
syslog_identifier = strappend ( " SYSLOG_IDENTIFIER= " , identifier ) ;
if ( syslog_identifier )
IOVEC_SET_STRING ( iovec [ n + + ] , syslog_identifier ) ;
}
if ( pid ) {
syslog_pid = strappend ( " SYSLOG_PID= " , pid ) ;
if ( syslog_pid )
IOVEC_SET_STRING ( iovec [ n + + ] , syslog_pid ) ;
}
}
2015-04-06 21:11:41 +03:00
if ( cunescape_length_with_prefix ( p , pl , " MESSAGE= " , UNESCAPE_RELAX , & message ) > = 0 )
2012-08-22 05:09:44 +04:00
IOVEC_SET_STRING ( iovec [ n + + ] , message ) ;
2017-07-18 00:36:35 +03:00
server_dispatch_message ( s , iovec , n , ELEMENTSOF ( iovec ) , NULL , NULL , priority , 0 ) ;
2012-08-22 05:09:44 +04:00
finish :
for ( j = 0 ; j < z ; j + + )
free ( iovec [ j ] . iov_base ) ;
free ( message ) ;
free ( syslog_priority ) ;
free ( syslog_identifier ) ;
free ( syslog_pid ) ;
free ( syslog_facility ) ;
free ( source_time ) ;
free ( identifier ) ;
free ( pid ) ;
}
2013-12-11 23:13:44 +04:00
static int server_read_dev_kmsg ( Server * s ) {
2012-08-22 05:09:44 +04:00
char buffer [ 8192 + 1 ] ; /* the kernel-side limit per record is 8K currently */
ssize_t l ;
assert ( s ) ;
assert ( s - > dev_kmsg_fd > = 0 ) ;
l = read ( s - > dev_kmsg_fd , buffer , sizeof ( buffer ) - 1 ) ;
if ( l = = 0 )
return 0 ;
if ( l < 0 ) {
/* Old kernels who don't allow reading from /dev/kmsg
* return EINVAL when we try . So handle this cleanly ,
* but don ' try to ever read from it again . */
if ( errno = = EINVAL ) {
2013-12-11 23:13:44 +04:00
s - > dev_kmsg_event_source = sd_event_source_unref ( s - > dev_kmsg_event_source ) ;
2012-08-22 05:09:44 +04:00
return 0 ;
}
if ( errno = = EAGAIN | | errno = = EINTR | | errno = = EPIPE )
return 0 ;
2015-11-05 15:44:20 +03:00
return log_error_errno ( errno , " Failed to read from kernel: %m " ) ;
2012-08-22 05:09:44 +04:00
}
dev_kmsg_record ( s , buffer , l ) ;
return 1 ;
}
int server_flush_dev_kmsg ( Server * s ) {
int r ;
assert ( s ) ;
if ( s - > dev_kmsg_fd < 0 )
return 0 ;
if ( ! s - > dev_kmsg_readable )
return 0 ;
2012-09-06 11:32:51 +04:00
log_debug ( " Flushing /dev/kmsg... " ) ;
2012-08-22 05:09:44 +04:00
for ( ; ; ) {
r = server_read_dev_kmsg ( s ) ;
if ( r < 0 )
return r ;
if ( r = = 0 )
break ;
}
return 0 ;
}
2013-12-11 23:13:44 +04:00
static int dispatch_dev_kmsg ( sd_event_source * es , int fd , uint32_t revents , void * userdata ) {
Server * s = userdata ;
assert ( es ) ;
assert ( fd = = s - > dev_kmsg_fd ) ;
assert ( s ) ;
if ( revents & EPOLLERR )
log_warning ( " /dev/kmsg buffer overrun, some messages lost. " ) ;
if ( ! ( revents & EPOLLIN ) )
log_error ( " Got invalid event from epoll for /dev/kmsg: % " PRIx32 , revents ) ;
return server_read_dev_kmsg ( s ) ;
}
2012-08-22 05:09:44 +04:00
int server_open_dev_kmsg ( Server * s ) {
2017-07-15 14:57:52 +03:00
mode_t mode ;
2013-12-11 23:13:44 +04:00
int r ;
2012-08-22 05:09:44 +04:00
assert ( s ) ;
2017-07-15 14:57:52 +03:00
if ( s - > read_kmsg )
mode = O_RDWR | O_CLOEXEC | O_NONBLOCK | O_NOCTTY ;
else
mode = O_WRONLY | O_CLOEXEC | O_NONBLOCK | O_NOCTTY ;
s - > dev_kmsg_fd = open ( " /dev/kmsg " , mode ) ;
2012-08-22 05:09:44 +04:00
if ( s - > dev_kmsg_fd < 0 ) {
2013-12-17 22:56:06 +04:00
log_full ( errno = = ENOENT ? LOG_DEBUG : LOG_WARNING ,
" Failed to open /dev/kmsg, ignoring: %m " ) ;
2012-08-22 05:09:44 +04:00
return 0 ;
}
2017-07-15 14:57:52 +03:00
if ( ! s - > read_kmsg )
return 0 ;
2014-02-20 02:54:58 +04:00
r = sd_event_add_io ( s - > event , & s - > dev_kmsg_event_source , s - > dev_kmsg_fd , EPOLLIN , dispatch_dev_kmsg , s ) ;
2013-12-11 23:13:44 +04:00
if ( r < 0 ) {
2012-08-22 05:09:44 +04:00
/* This will fail with EPERM on older kernels where
* / dev / kmsg is not readable . */
2013-12-17 22:57:13 +04:00
if ( r = = - EPERM ) {
r = 0 ;
goto fail ;
}
2012-08-22 05:09:44 +04:00
2014-11-28 15:19:16 +03:00
log_error_errno ( r , " Failed to add /dev/kmsg fd to event loop: %m " ) ;
2013-12-17 22:57:13 +04:00
goto fail ;
2013-12-11 23:13:44 +04:00
}
r = sd_event_source_set_priority ( s - > dev_kmsg_event_source , SD_EVENT_PRIORITY_IMPORTANT + 10 ) ;
if ( r < 0 ) {
2014-11-28 15:19:16 +03:00
log_error_errno ( r , " Failed to adjust priority of kmsg event source: %m " ) ;
2013-12-17 22:57:13 +04:00
goto fail ;
2012-08-22 05:09:44 +04:00
}
s - > dev_kmsg_readable = true ;
return 0 ;
2013-12-17 22:57:13 +04:00
fail :
2014-03-18 22:22:43 +04:00
s - > dev_kmsg_event_source = sd_event_source_unref ( s - > dev_kmsg_event_source ) ;
s - > dev_kmsg_fd = safe_close ( s - > dev_kmsg_fd ) ;
2013-12-17 22:57:13 +04:00
return r ;
2012-08-22 05:09:44 +04:00
}
int server_open_kernel_seqnum ( Server * s ) {
2014-03-18 22:22:43 +04:00
_cleanup_close_ int fd ;
2012-08-22 05:09:44 +04:00
uint64_t * p ;
2015-11-05 15:44:07 +03:00
int r ;
2012-08-22 05:09:44 +04:00
assert ( s ) ;
/* We store the seqnum we last read in an mmaped file. That
* way we can just use it like a variable , but it is
2012-10-02 11:38:37 +04:00
* persistent and automatically flushed at reboot . */
2012-08-22 05:09:44 +04:00
fd = open ( " /run/systemd/journal/kernel-seqnum " , O_RDWR | O_CREAT | O_CLOEXEC | O_NOCTTY | O_NOFOLLOW , 0644 ) ;
if ( fd < 0 ) {
2014-11-28 21:29:59 +03:00
log_error_errno ( errno , " Failed to open /run/systemd/journal/kernel-seqnum, ignoring: %m " ) ;
2012-08-22 05:09:44 +04:00
return 0 ;
}
2015-11-05 15:44:07 +03:00
r = posix_fallocate ( fd , 0 , sizeof ( uint64_t ) ) ;
if ( r ! = 0 ) {
log_error_errno ( r , " Failed to allocate sequential number file, ignoring: %m " ) ;
2012-08-22 05:09:44 +04:00
return 0 ;
}
p = mmap ( NULL , sizeof ( uint64_t ) , PROT_READ | PROT_WRITE , MAP_SHARED , fd , 0 ) ;
if ( p = = MAP_FAILED ) {
2014-11-28 21:29:59 +03:00
log_error_errno ( errno , " Failed to map sequential number file, ignoring: %m " ) ;
2012-08-22 05:09:44 +04:00
return 0 ;
}
s - > kernel_seqnum = p ;
return 0 ;
}