A Complete Guide For Installing TFTP Server In CentOS 7

Posted by Bo Yang at 2015-08-31 with tags Notes , Unix/Linux


Since CentOS 7(or RedHat 7) is quite different from CentOS 6.x, most notes online for installing TFTP server in CentOS are obsolete already. This post not only summarizes the procedure of installing & configuring TFTP server, but also introduces a general strategy of configuring network services in CentOS 7.

1. Install tftp-server

TFTP server can be installed using following command, where xinetd is necessary.

yum install tftp tftp-server* xinetd*

Then edit /etc/xinetd.d/tftp - set disable to no and add -c option into server_args if you need to upload files to TFTP server from client.

service tftp
{
	socket_type		= dgram
	protocol		= udp
	wait			= yes
	user			= root
	server			= /usr/sbin/in.tftpd
	server_args		= -c -s /tftpboot
	disable			= no
	per_source		= 11
	cps			    = 100 2
	flags			= IPv4
}

2. Enable TFTP Service

The CentOS 7 services( systemd ) can be configured from files under /usr/lib/systemd/system/ . Go to this dir, and edit tftp.service as follows:

[root@localhost system]# cat tftp.service
[Unit]
Description=Tftp Server

[Service]
ExecStart=/usr/sbin/in.tftpd -c -s /tftpboot
StandardInput=socket

[Install]
WantedBy=multi-user.target

The default tftp.service doesn’t have the [Install] unit, but it’s required by systemd . Besides, the tftpd options also need to be changed in the ExecStart entry.

Although service commands are deprecated in CentOS 7, they are still available but simply redirected to systemctl . So you still can use service xinetd start and service tftp start to start xinetd and TFTP.

However, to make them automatically start after boot, following commands are needed:

[root@localhost system]# systemctl enable xinetd
[root@localhost system]# systemctl enable tftp

After these two commands, permanent links will be made for xinetd and TFTP services.

3. Configure SELinux

In CentOS 7, the SELinux is not supposed to be disabled(the system will abort booting if you disable SELinux). So the TFTP read and write must be allowed in SELinux. By default, the SELinux uses enforcing policy, which does not accept any change. To make any change to SELinux, first modify /etc/selinux/config and change the policy to permissive :

[bo@ucs-c200 notes]$ cat /etc/selinux/config 

# This file controls the state of SELinux on the system.
# SELINUX= can take one of these three values:
#     enforcing - SELinux security policy is enforced.
#     permissive - SELinux prints warnings instead of enforcing.
#     disabled - No SELinux policy is loaded.
SELINUX=permissive
# SELINUXTYPE= can take one of three two values:
#     targeted - Targeted processes are protected,
#     minimum - Modification of targeted policy. Only selected processes are protected. 
#     mls - Multi Level Security protection.
SELINUXTYPE=targeted 

Then reboot the system. After system boot up, check SELinux status:

[root@localhost system]# sestatus
SELinux status:                 enabled
SELinuxfs mount:                /sys/fs/selinux
SELinux root directory:         /etc/selinux
Loaded policy name:             targeted
Current mode:                   permissive
Mode from config file:          permissive
Policy MLS status:              enabled
Policy deny_unknown status:     allowed
Max kernel policy version:      28

Then check the tftp permissions in SELinux:

[root@localhost bobyan]# getsebool -a | grep tftp
tftp_anon_write --> off
tftp_home_dir --> off

If the TFTP write is off as shown above, enable it with setsebool command:

[root@localhost bobyan]# setsebool -P tftp_anon_write 1
[root@localhost bobyan]# setsebool -P tftp_home_dir 1

Above changes to SELinux are permanent, so no need to change any SELinux config files any more.

4. Configure firewalld

Unlike CentOS 6.x, the firewalld is used to replace iptables as default firewall in CentOS 7. Fortunately, iptable config file /etc/sysconfig/iptables is also used by firewalld . So to allow TFTP services, following line should be added to /etc/sysconfig/iptables

-A INPUT -m state --state NEW -m udp -p udp -m udp --dport 69 -j ACCEPT

Then restart firewalld using command firewall-cmd --reload .

A more standard way to allow TFTP is to use firewall-cmd command:

firewall-cmd --zone=public --add-service=tftp --permanent

Where the --permanent option is used to permanently enable the TFTP port. Command firewall-cmd --reload is needed every time changing the firewall config.

To check the status or enable firewalld , following commands can be used:

systemctl status firewalld
systemctl enable firewalld
systemctl start firewalld

How To Use Local Facilities For Logging?

Posted by Bo Yang at 2015-08-20 with tags Notes , Unix/Linux


This post introduces how to configure and use syslogd-compatible syslog tools. These tips should be supported by rsyslog, but rsyslog-specific commands are not covered.

As documented in the man page, the Linux system log is configured in file /etc/syslog.conf by default.You can specify other config file with -f option for syslogd. The format of syslog config file is

<facility>.<priority>   [logfile]

The supported facilities and priorites are defined in syslog.h :

#define	LOG_EMERG	0	/* system is unusable */
#define	LOG_ALERT	1	/* action must be taken immediately */
#define	LOG_CRIT	2	/* critical conditions */
#define	LOG_ERR		3	/* error conditions */
#define	LOG_WARNING	4	/* warning conditions */
#define	LOG_NOTICE	5	/* normal but significant condition */
#define	LOG_INFO	6	/* informational */
#define	LOG_DEBUG	7	/* debug-level messages */

/* facility codes */
#define	LOG_KERN	(0<<3)	/* kernel messages */
#define	LOG_USER	(1<<3)	/* random user-level messages */
#define	LOG_MAIL	(2<<3)	/* mail system */
#define	LOG_DAEMON	(3<<3)	/* system daemons */
#define	LOG_AUTH	(4<<3)	/* security/authorization messages */
#define	LOG_SYSLOG	(5<<3)	/* messages generated internally by syslogd */
#define	LOG_LPR		(6<<3)	/* line printer subsystem */
#define	LOG_NEWS	(7<<3)	/* network news subsystem */
#define	LOG_UUCP	(8<<3)	/* UUCP subsystem */
#define	LOG_CRON	(9<<3)	/* clock daemon */
#define	LOG_AUTHPRIV	(10<<3)	/* security/authorization messages (private) */
#define	LOG_FTP		(11<<3)	/* ftp daemon */

/* other codes through 15 reserved for system use */
#define	LOG_LOCAL0	(16<<3)	/* reserved for local use */
#define	LOG_LOCAL1	(17<<3)	/* reserved for local use */
#define	LOG_LOCAL2	(18<<3)	/* reserved for local use */
#define	LOG_LOCAL3	(19<<3)	/* reserved for local use */
#define	LOG_LOCAL4	(20<<3)	/* reserved for local use */
#define	LOG_LOCAL5	(21<<3)	/* reserved for local use */
#define	LOG_LOCAL6	(22<<3)	/* reserved for local use */
#define	LOG_LOCAL7	(23<<3)	/* reserved for local use */

The local facilities can be used for redirecting/filtering the log of your own programs. For example, given a program foo , if you want to log all the non-critical messages in /var/log/foo.log , and make the critical logs go to system log file /var/log/messages , you can use the following config file

# use facility local1 for foo logs
local1.debug;local1.info;local1.notice;local1.warn   -/var/log/foo.log
local1.panic;local1.alert;local1.crit;local1.err   -/var/log/messages
*.*;local1.none   /var/log/messages 

The special priority none prevents those messages from being logged even though they would have been included in the . . In the above config, all facilities except for local1 will be logged to /var/log/messages .

However, the dash(-) in front of the log filename is not documented in the man page, but it turns out to mean “Don’t sync after every write to the file”. Except that rsyslogd won’t sync anyway, unless you add a special directive in the Global Directives section. Note that you might lose information if the system crashes right behind a write attempt. Nevertheless this might give you back some performance, especially if you run programs that use logging in a very verbose manner. So for most people, a dash makes no difference one way or the other – it will be ignored.

And in program foo , what you need to do is open log file by specifing LOG_LOCAL1 facility. The use of openlog() is mandatory here. Otherwise, it will automatically be called by syslog(), in which case facility will default to LOG_USER .

#include <syslog.h>
int main(int, char**)
{
    openlog("foo", 0, LOG_LOCAL1);
    syslog(LOG_INFO, "test info log"); /* go to /var/log/foo.log */
    syslog(LOG_ERR, "test error log"); /* go to /var/log/messages */
    closelog();
}

References

Retrieve Last Log After Crash

Posted by Bo Yang at 2015-05-27 with tags Notes , Unix/Linux


In Linux, there are two kinds of crashes - kernel panic/oom and user space core dump. For kernel panic, the standard config is rebooting the system. Unfortunately, the panic log can only be printed to console and will disappear after reboot if there is no additional device to record the console log - most kernel panic/oom logs won’t be written to system log, and even they do, there is no way to sync them to disk storage during panic.

As for user-sapce core dump, core files will be generated to /tmp/pid.core (core pattern can be changed in /proc/sys/kernel/core_pattern ) by default. It is up to the admin to decide if the system or process needs reboot after core dump. Although a script can be used to record more logs for the coredump, sometimes it’s still useful to retain some info in the persistent memory, like the backtrace of the coredumped process.

Modules Needed

phram is a Memory Technology Device(MTD) driver, which supports accessing non-system memory, i.e. from the PCI address space. This module can act as a special memory file to store important data during reboots.

ramoops is an kernel oops/panic logger that writes its logs to predefined memory area before the system crashes. It works by logging oopses and panics in a circular buffer. As long as the device has power supply during reboot, the content stored in ramoops won’t go away.

Both phram and ramoops can be compiled to .ko shared library, which can be configured using Linux menuconfig.

Loading Modules

phram can be dynamically loaded using following command:

insmod /lib/modules/phram.ko phram=<name>,<addr>,<len>

where <name> is the device(i.e. file) name under /dev/mtdchar/ , <addr> is the reserved starting memory address, and <len> is the predefined length of the memory area.

To load ramoops

insmod /lib/modules/ramoops.ko mem_address=<addr> mem_size=<len> [record_size=<chunks>]

where <addr> and <len> have the same meaning as above, and record_size is the chunks of reserved memory area.

Copy Log To phram Memory

For kernel panic, the ramoops will automatically copy the panic log into the reserved memory. The panic log begins with leading “====” followed by a timestamp and a new line.

If you need to store other info, dd command can be used to copy file to the memory, e.g.

dd if=/var/log/messages bs=1 count=65536 skip=<fsize - len> of=/dev/mtdchar/phram-oops

According to dd manual, if is the the input file stream, of is the output file, bs specifies the bytes to be read and write at a time, and skip configs the input blocks to be skipped from the input file. Here the size of block is defined by bs . In the above example, the block size is set to 1 byte, and only the last len bytes will be copied to phram memory.

Unfortunately, reading & writing byte-by-byte usaully is very slow. A faster way is setting bs to a larger number, like 128, 512, 1024, etc. In this case, the skip and count need to be calculated correspondingly: say the size of reserved memory is len , input file size is fsize , bs is set to bsize , then

// len: memory size
// fsize: input file size
bs = bsize
if (fsize <= bsize)
    skip =  0;
else
    skip = (fsize - len)/bsize + 1;
count = len/bsize + 1;

Dump Last Log

dd command can also be used for dumping data from reserved phram memory area, e.g.

dd if=/dev/mtdchar/phram-oops bs=<len> count=1

Other file operation commands/APIs can also be used for phram memory device.

Reset phram Memory

phram memory can be cleared by file operation coomands/APIS, e.g.

dd if=/dev/zero bs=<len> count=1 of=/dev/mtdchar/phram-oops

References

  1. Use Memory On Video Card As Swap
  2. Ramoops oops/panic logger
  3. dd manual

Customizing OpenWRT System Log Timestamp

Posted by Bo Yang at 2015-04-02 with tags Notes , Unix/Linux


As explained in previous post Linux System Log , threre is no way to directly change the default timestamps printed on Linux console. However, it is still possible to get human readable timestamp without using fancy syslog tools like syslog-ng .

A bash script of customizing Linux dmesg timestamp is also given in my post post Linux System Log . Unfortunately, that script won’t work if bash is not available in your Linux system. For example, the default shell in OpenWRT is Busybox ash, which lacks many powerful features of bash. The most significant shortcoming for ash is the lame arithmetic operations. In addition, many useful options for standard commands are not supported in Busybox ash. Fortunately, we have sed and awk installed in OpenWRT. So the arithmetic operations can be done by awk.

The basic idea of customizing console syslog timestamp is periodically calling dmesg -c , which clears system circular buffer after dumping the system log. In order to also store the log in syslog file(like /var/log/messages), the dumped message also needs to be redirected(or appending) to the syslog file. The timestamps of dmesg can be replaced with a human readable one. And the required addition/subtraction is implemented by awk in a very special way.

Instead of `dmesg`, someone may be tempted to use command `tail -f /var/log/messages`. Unfortunately, the `tail` command would automatically stop printing from `/var/log/messages` after a while. It may be caused by the implementation of Busybox `tail` or OpenWRT system log mechanism.

Although tail -f /var/log/messages would automatically stop after some time, the -F option works for ash tail command, i.e. tail -F /var/log/messages .

Following is the source code in ash :

#!/bin/ash

#
# This script is used to tail the latest syslogs to stdout,
# syslog file and specified log file.
#

SYSLOG=/var/log/messages
custom_log=
[ ! -z "$1" ] && custom_log=$1

base=$(cut -d" " -f1 /proc/uptime);
ut=$(date +%s);
# FIXME: Arithmetic operations are not fully supported in ash, use awk instead.
base=`date | awk "{now=$ut - $base; printf \"%d\", now}"`

dmesg -c >> $SYSLOG # clear circular syslog buffer
while true
do
    dmesg -c | sed "s/^\[[ ]*\?\([0-9.]*\)\] \(.*\)/\\1 \\2/" |
    while read ts msg; do
        now=`date | awk "{now=$base + $ts; printf \"%d\", now}"`
        newts=`date +"%m/%d/%Y %H:%M:%S" --date "@$now"` # human readable timestamp
        printf "[%s] %s\n" "$newts" "$msg";
    done | sed "s/$/$(printf '\r')/" | tee -a $SYSLOG $custom_log

    sleep 1
done

Debug Kernel Space Memory Leak

Posted by Bo Yang at 2015-03-30 with tags Notes , Unix/Linux


1. Detect Memory Leak

Memory leak can be detected by monitoring the free memory periodically. Command free can be used to show rough memory usage. A more detailed way to analyze memroy is cat /proc/meminfo and cat /proc/slabinfo . /proc/meminfo contains info about total memory, free memory, total highmem, free highmem, total lowmem, free lowmem and etc. Usually highmem is user-space memory, while lowmem is kernel-space memory. If free highmem(HighFree) or free lowmem(LowFree) is continuously decreasing, in most cases it means user space or kernel space memory leaking.

Once detected memory leaking, we need to determine which slab(s) is(are) leaking. This can be done by monitoring /proc/slabinfo . If the number of a slab’s active objects(column 2) or total objects(column 3) keep increasing, then this slab is very likely leaking memory.

Following script can be used to monitor both meminfo and slabinfo:

#!/bin/sh

MAX_SIZE=20000000
MON_FILE=/path/to/monitor_output_$(uname -n)
while true
do
    date >> $MON_FILE
    cat /proc/meminfo >> $MON_FILE
    echo "----------------------" >> $MON_FILE
    cat /proc/slabinfo >> $MON_FILE
    echo "----------------------" >> $MON_FILE
    ps -o pid,comm,stat,time,rss,vsz >> $MON_FILE
    echo "++++++++++++++++++++++" >> $MON_FILE
    fsize=`ls -l $MON_FILE | awk '{print $5}'`
    if [ $fsize -gt $MAX_SIZE ]; then
    	# upload file to TFTP server
        suffix=`cat /proc/uptime | cut -d" " -f1`
        mv $MON_FILE $MON_FILE.$suffix
        # upload to cloud
    fi
    sleep 300
done

After continuously monitoring for hours, simply grep some keywords(e.g. HighFree, LowFree, kmalloc-192, etc.) could find the trend of memory usage. Following data is extracted from a real memory leak monitoring log:

LowFree:          599392 kB
LowFree:          571072 kB
LowFree:          544484 kB
LowFree:          516832 kB
LowFree:          489232 kB
LowFree:          462280 kB
LowFree:          433680 kB
LowFree:          405244 kB
LowFree:          378572 kB
LowFree:          350136 kB
LowFree:          322648 kB
LowFree:          295824 kB
LowFree:          267532 kB
LowFree:          238272 kB
LowFree:          210856 kB
LowFree:          181148 kB
LowFree:          153652 kB
LowFree:          123148 kB
LowFree:          599392 kB
LowFree:          571072 kB
LowFree:          544484 kB
LowFree:          181148 kB
LowFree:          153652 kB
LowFree:          123148 kB
LowFree:           94548 kB
LowFree:           94548 kB

2. Debug Memory Leak

After finding out the leaking slab, more info could be detected by tracing that slab. If the kernel was built with option CONFIG_SLUB_DEBUG , the simplest way is to issue command echo 1 > /sys/kernel/slab/<leaking_slab>/trace . Then the memory allocation trace for this slab will be printed to the console:

[  375.201468] TRACE kmalloc-4096 alloc 0xe6be6000 inuse=8 fp=0x  (null)
[  375.207872] Backtrace:
[  375.210309] [<c0012378>] (dump_backtrace+0x0/0x114) from [<c03a0a5c>] (dump_stack+0x18/0x1c)
[  375.218712]  r6:ef300480 r5:e6be6000 r4:c0d40c00 r3:c07004c4
[  375.224367] [<c03a0a44>] (dump_stack+0x0/0x1c) from [<c03a2738>] (alloc_debug_processing+0xc8/0x164)
[  375.233489] [<c03a2670>] (alloc_debug_processing+0x0/0x164) from [<c03a2d0c>] (__slab_alloc.isra.50.constprop.56+0x538/0x5dc)
[  375.244767]  r7:80080008 r6:00080007 r5:e6be6000 r4:c0d40c00
[  375.250421] [<c03a27d4>] (__slab_alloc.isra.50.constprop.56+0x0/0x5dc) from [<c00e872c>] (__kmalloc_track_caller+0xbc/0x190)
[  375.261605] [<c00e8670>] (__kmalloc_track_caller+0x0/0x190) from [<c031f96c>] (__alloc_skb+0x58/0xf4)
[  375.270790] [<c031f914>] (__alloc_skb+0x0/0xf4) from [<c03200d4>] (dev_alloc_skb+0x40/0x64)
[  375.279131] [<c0320094>] (dev_alloc_skb+0x0/0x64) from [<bf6bb504>] (__adf_nbuf_alloc+0x24/0xa4 [adf])
[  375.288409]  r4:ea5c8600 r3:00000004
[  375.292158] [<bf6bb4e0>] (__adf_nbuf_alloc+0x0/0xa4 [adf]) from [<bf8d5f40>] (htt_rx_ring_fill_n+0x34/0x108 [umac])
[  375.302405]  r7:00000000 r6:000005b1 r5:ea5c8720 r4:ea5c8600
[  375.308372] [<bf8d5f0c>] (htt_rx_ring_fill_n+0x0/0x108 [umac]) from [<bf8d6888>] (htt_rx_msdu_buff_replenish+0x54/0x6c [umac])
[  375.319400]  r8:bf927c04 r7:eaaee9c0 r6:eb5b3c00 r5:ea5c8720 r4:ea5c8600
[  375.326429] [<bf8d6834>] (htt_rx_msdu_buff_replenish+0x0/0x6c [umac]) from [<bf8c6b24>] (ol_rx_indication_handler+0x7bc/0x8cc [umac])
[  375.338081]  r5:ea5c8600 r4:00000000
[  375.341955] [<bf8c6368>] (ol_rx_indication_handler+0x0/0x8cc [umac]) from [<bf8d770c>] (htt_t2h_msg_handler_fast+0xac/0x280 [umac])
[  375.353764] [<bf8d7660>] (htt_t2h_msg_handler_fast+0x0/0x280 [umac]) from [<bf8c02dc>] (CE_per_engine_service_each+0x178/0x4b4 [umac])
[  375.365823] [<bf8c0164>] (CE_per_engine_service_each+0x0/0x4b4 [umac]) from [<bf8c3634>] (ath_tasklet+0x68/0x128 [umac])
[  375.376507] [<bf8c35cc>] (ath_tasklet+0x0/0x128 [umac]) from [<c0064478>] (tasklet_action+0xa0/0x11c)
[  375.385567]  r6:e8b88000 r5:c435ef44 r4:c435ef40
[  375.390159] [<c00643d8>] (tasklet_action+0x0/0x11c) from [<c006495c>] (__do_softirq+0x140/0x34c)
[  375.398937] [<c006481c>] (__do_softirq+0x0/0x34c) from [<c0064d38>] (do_softirq+0x4c/0x58)
[  375.407185] [<c0064cec>] (do_softirq+0x0/0x58) from [<c0064dd0>] (local_bh_enable_ip+0x8c/0xcc)
[  375.415870]  r4:e8b88000 r3:0000004a
[  375.419431] [<c0064d44>] (local_bh_enable_ip+0x0/0xcc) from [<c03aa68c>] (_raw_spin_unlock_bh+0x54/0x58)
[  375.428865]  r5:00000304 r4:e9662c00
[  375.432427] [<c03aa638>] (_raw_spin_unlock_bh+0x0/0x58) from [<c038a47c>] (packet_poll+0xa4/0xe4)
[  375.441299] [<c038a3d8>] (packet_poll+0x0/0xe4) from [<c0316e34>] (sock_poll+0x24/0x28)
[  375.449265]  r7:ea9ffe40 r6:00000000 r5:e8b89c4c r4:e8b89c04
[  375.454920] [<c0316e10>] (sock_poll+0x0/0x28) from [<c00fc914>] (do_sys_poll+0x20c/0x3e8)
[  375.463074] [<c00fc708>] (do_sys_poll+0x0/0x3e8) from [<c00fcbb0>] (sys_poll+0x64/0xd0)
[  375.471071] [<c00fcb4c>] (sys_poll+0x0/0xd0) from [<c000e7c0>] (ret_fast_syscall+0x0/0x30)
[  375.479318]  r6:0007a120 r5:00000000 r4:6b3f60a0

The first line could only be “TRACE kmalloc-4096 alloc” or “free”, which logs the entry address of this slab. So if the memory leak is very fast, it is possible to monitor all of the alloc/free slabs before the system out of memory. Then find out addresses that never freed, analyze the call traces, and hopefull we could detect the problematic module or functions.

Linux System Log

Posted by Bo Yang at 2015-01-12 with tags Notes , Unix/Linux


  1. Overview
  2. printk
  3. klogd
  4. syslog
  5. dmesg
  6. syslog-ng
  7. Convert Timestamp

1. Overview

Linux adopts a ring buffer in kernel with a size of __LOG_BUF_LEN bytes to store system logs, where __LOG_BUF_LEN equals ( 1 << CONFIG_LOG_BUF_SHIFT ) (see kernel/printk.c for details). Using a ring buffer implies that older messages get overwritten once the buffer fills up, but this is only a minor drawback compared to the robustness of this solution (i.e. minimum memory footprint, callable from every context, not many resources wasted if nobody reads the buffer, no filling up of disk space/ram when some kernel process goes wild and spams the buffer, …). Using a reasonably large buffer size should give you enough time to read your important messages before they are overwritten.

The kernel log buffer is accessible for reading from userspace by /proc/kmsg . /proc/kmsg behaves more or less like a FIFO and blocks until new messages appear. Please note, reading from /proc/kmsg consumes the messages in the ring buffer so they may not be available for other programs. It is usually a good idea to let klogd or syslog do this job and read the content of the buffer via dmesg.

Linux Kernel Log

2. printk

printk is the kernel function to classify messages according to their severity by loglevels and write them to the circular system message buffer. The function then wakes any process that is waiting for messages, that is, any process that is sleeping in the syslog system call or that is reading /proc/kmsg . printk can be invoked from anywhere, even from an interrupt handler, with no limit on how much data can be printed.

printk( KERN_CRIT "Error code %08x.\n", val );

There are eight possible loglevel strings, defined in the header <linux/kernel.h>; we list them in order of decreasing severity:

Name String Meaning alias function
KERN_EMERG “0” Emergency messages, system is about to crash or is unstable pr_emerg
KERN_ALERT “1” Something bad happened and action must be taken immediately pr_alert
KERN_CRIT “2” A critical condition occurred like a serious hardware/software failure pr_crit
KERN_ERR “3” An error condition, often used by drivers to indicate difficulties with the hardware pr_err
KERN_WARNING “4” A warning, meaning nothing serious by itself but might indicate problems pr_warning
KERN_NOTICE “5” Nothing serious, but notably nevertheless. Often used to report security events. pr_notice
KERN_INFO “6” Informational message e.g. startup information at driver initialization pr_info
KERN_DEBUG “7” Debug messages pr_debug, pr_devel if DEBUG is defined
KERN_DEFAULT “d” The default kernel loglevel
KERN_CONT ”” “continued” line of log printout (only done after a line that had no enclosing \n ) pr_cont

Each string (in the macro expansion) represents an integer in angle brackets. Integers range from 0 to 7, with smaller values representing higher priorities.

A printk statement with no specified priority defaults to DEFAULT_MESSAGE_LOGLEVEL , specified in kernel/printk.c as an integer. For this the kernel compares the log level of the message to the console_loglevel (a kernel variable) and if the priority is higher (i.e. a lower value) than the console_loglevel the message will be printed to the current console. The console_loglevel can be checked by

# cat /proc/sys/kernel/printk
7       4       1       7

The first integer shows you your current console_loglevel ; the second is the DEFAULT_MESSAGE_LOGLEVEL .

Kernel log timestamp is added by vprintk() , in kernel/printk.c :

#if defined(CONFIG_PRINTK_TIME)
static bool printk_time = 1;
#else
static bool printk_time = 0;
#endif

if (printk_time) {
		/* Add the current time stamp */
		char tbuf[50], *tp;
		unsigned tlen;
		unsigned long long t;
		unsigned long nanosec_rem;

		t = cpu_clock(printk_cpu);
		nanosec_rem = do_div(t, 1000000000);
		tlen = sprintf(tbuf, "[%5lu.%06lu] ",
				(unsigned long) t,
				nanosec_rem / 1000);

		for (tp = tbuf; tp < tbuf + tlen; tp++)
			emit_log_char(*tp);
		printed_len += tlen;
}

3. klogd

If the klogd process is running, it retrieves kernel messages and dispatches them to syslogd , which in turn checks /etc/syslog.conf to find out how to deal with them. syslogd differentiates between messages according to a facility and a priority; allowable values for both the facility and the priority are defined in <sys/syslog.h> . Kernel messages are logged by the LOG_KERN facility at a priority corresponding to the one used in printk (for example, LOG_ERR is used for KERN_ERR messages). If klogd isn’t running, data remains in the circular buffer until someone reads it or the buffer overflows.

If you want to avoid clobbering your system log with the monitoring messages from your driver, you can either specify the (file) option to klogd to instruct it to save messages to a specific file, or customize /etc/syslog.conf to suit your needs. Yet another possibility is to take the brute-force approach: kill klogd and verbosely print messages on an unused virtual terminal, or issue the command cat /proc/kmsg from an unused xterm.

4. syslog

Accessing to the log buffer is provided at the core through the multi-purpose syslog system call. The prototype for the syslog system call is defined in ./linux/include/linux/syslog.h ; its implementation is in ./linux/kernel/printk.c .

The syslog call serves as the input/output (I/O) and control interface to the kernel’s log message ring buffer. From the syslog call, an application can read log messages (partial, in their entirety, or only new messages) as well as control the behavior of the ring buffer (clear contents, set the level of messages to be logged, enable or disable console, and so on).

Although reading from /proc/kmsg consumes the data from the log buffer, the syslog system call can optionally return log data while leaving it for other processes as well.

Kernel space syslog API:

#include <syslog.h>

void openlog(const char *ident, int option, int facility);
void syslog(int priority, const char *format, ...);
void closelog(void);

#include <stdarg.h>

void vsyslog(int priority, const char *format, va_list ap);
  • closelog() closes the descriptor being used to write to the system logger.
  • openlog() opens a connection to the system logger for a program.
  • syslog() generates a log message, which will be distributed by syslogd . It does this by writing to the Unix domain socket /dev/log .
  • vsyslog() is functionally identical to syslog() , with the BSD style variable length argument.

User space syslog API(glibc wrapper):

int syslog( int type, char *bufp, int len );
int klogctl( int type, char *bufp, int len );

klogctl() is the glibc wrapper to control the kernel printk() buffer.

5. dmesg

The dmesg command is used to print and control the kernel ring buffer. This command uses the klogctl system call to read the kernel ring buffer and emit it to standard output (stdout). The command can also be used to clear the kernel ring buffer (using the -c option), set the level for logging to the console (the -n option), and define the size of the buffer used to read the kernel log messages (the -s option).

dmesg reads by default a buffer of max 16392 bytes, so if you use a larger log buffer you have to invoke dmesg with the -s parameter e.g.:

### CONFIG_LOG_BUF_SHIFT 17 = 128k
$ dmesg -s 128000

6. syslog-ng

The syslog-ng application is a flexible and highly scalable system logging application that is ideal for creating centralized and trusted logging solutions. It extends the original syslogd model with content-based filtering, rich filtering capabilities, flexible configuration options and adds important features to syslog.

syslog-ng also supports ISO/RFC timestamp for system logs. For more info about this powerful log system, please refer to the manual .

7. Converting Timestamps

By default the time stamps are printed in “seconds since boot” (this is the way the kernel is programmed to print the time stamps in vprintk() , and it can not be changed to print the time stamps in a human readable format). The system uptime can be helpful to calculate an absolute time stamp if needed (run the uptime command).

Given timestamp:

[196149.728085] hello world

The algorithm below converts the printed time stamps to a human readable format:

1. Take the log's time stamp in seconds: 

196149.728085 seconds (round the number down/up if needed) 

2. Divide the time stamp in seconds by 60 to get the total amount of minutes: 

196150 : 60 = 3269.1667 minutes (round the number down/up if needed) 

3. Divide the time stamp in minutes by 60 to get the total amount of hours: 

3269.1667 : 60 = 54.486111666666666666666666666667 hours 

4. Break the decimal number into 2 parts: 

54.486111666666666666666666666667 hours = (54 hours) + (0.486111666666666666666666666667 decimal hours) 

5. Use the time conversion charts below to convert decimal hours to minutes: 

0.486111666666666666666666666667 decimal hours ~ 0.48 decimal hours ~ 29 minutes 

6. Note: For more precise conversion (down to seconds), you can use various time converters available on the Internet. Just search for 'convert decimal time' in any search engine. 

7. Hence, we get that the log was created this amount of time since boot: 

196149.728085 seconds ~ 54 hours 29 minutes 

8. Check the current system's uptime: 

[Expert@HostName]# uptime 

9. To get the log's real time stamp, subtract the log's time stamp in dmesg kernel ring buffer from the current system's uptime.

Following is a Shell script to transform uptime timestamp to human-readable timestamp:

#!/bin/bash
# Translate dmesg timestamps to human readable format

# desired date format
date_format="%a %b %d %T %Y"

# uptime in seconds
uptime=$(cut -d " " -f 1 /proc/uptime)

# run only if timestamps are enabled
if [ "Y" = "$(cat /sys/module/printk/parameters/time)" ]; then
  dmesg | sed "s/^\[[ ]*\?\([0-9.]*\)\] \(.*\)/\\1 \\2/" | while read timestamp message; do
    #date +"%s" -d "1970-01-01 00:00:00"
    #awk '{printf("%d:%02d:%02d\n", ($1/3600), ($1%3600/60),($1%60))}' /proc/uptime
    printf "[%s] %s\n" "$(date --date "now - $uptime seconds + $timestamp seconds" +"${date_format}")" "$message"
  done
else
  echo "Timestamps are disabled (/sys/module/printk/parameters/time)"
fi

References

Click Notes II - Click Script Language

Posted by Bo Yang at 2015-01-07 with tags Notes , Click , Network


The Click programming language was developed to configure Click routers, but nowadays you also can use it to write test cases for Click elements.

  1. Basic Syntax
  2. Element Group
  3. Compound Element
  4. Script
  5. Testie

Basic Syntax

The Click Script Language defines a configuration graph, which consists of connected elements. Each element has an element class specified by class name. Elements are connected through their input and output ports. Input and output ports are distinguished by number, while elements are distinguished by name.

Click configuration strings are comma-separated lists of arguments delimited by parentheses. The fundamental syntax of Click Script Language is:

name :: class(config-string);    // declare element object
name1, name2, ..., nameN :: class(config); // declaration shorhand
name1[port1] -> [port2]name2;    // connect two elements
name1[port1] -> [port2a]name2[port2b] -> [port3]name3;    // piggyback connections
name1 -> name2 :: class(config-string) -> name3;  // declaring elements inside connections is allowed
name1 -> class(config-string) -> name3;  // anonymous element
require(requirement[, requirement …]);   // list config requirements

n1, n2 :: class -> n3;  // many-to-one connections

// many-to-many connections:
// A many-to-many connection matches output ports to input ports. 
// There must be as many ports on the left as on the right.
// '=>' is the many-to-many connector.
c[0], c[1], c[2] => Paint(0), Paint(1), Paint(2) -> next;
c => Paint(0), Paint(1), Paint(2) -> next;

Element Group

An element group is one or more Click statements enclosed in parentheses. Within the parentheses, the special pseudoelements input and output refer to connections from outside the group. Click expands the group at parse time, so connections through input and output have no run-time overhead. The following five lines are equivalent:

x -> y;
x -> ( input -> output ) -> y;
x -> ( [0] -> [0] ) -> y;
x -> (->) -> y;
x -> ( [0]->[0]; [1]->[1] ) => ( [0]->[0]; [1]->[1] ) -> y;

Line five uses the fact that connections may be repeated without error (the line expands to x -> y; x -> y ), where the explicit semicolons are used to avoid ambiguity.

Element groups have implicit, overridable port specifications that list all their ports in sequential order. For example, these three lines are equivalent:

x => ( [0]->[0]; [1]->[1] ) -> y;
x => [0,1] ( [0]->[0]; [1]->[1] ) [0,1] -> y;
x -> y; x [1] -> y;

An element group does not define a new scope. Its contents may refer to elements declared outside of the group, and declarations inside the group are visible after the group closes. This differs from compound elements, described next, which have a related syntax but additionally introduce a new scope.

Compound Element

A compound element is a scoped collection of elements that behaves like a single element. A compound element can be used anywhere an element class is expected (that is, in a declaration or connection). Syntactically, a compound element is a set of Click statements enclosed in braces { } . Inside the braces, the special names input and output represent connections from or to the outside.

Compound element classes are router configuration fragments consisted by Click elements and statements that are treated like element classes. For compound elements, only components remain in the final configuration graph, and all compound element structure is compiled away. This process is called flattening , during which compound element components are given names that reflect their origin. For example, a component named e of a compound element compound is named compound/e in the flattened configuration.

elementclass Name {    // compound elements
    ... Click Statements …  // defined by click statements but not C++ class
}
e :: {    // anonymous compound element class
    ... Click Statements … 
}
elementclass MyQueue Queue;   // define an alias for an existing element class

Like any element, compound elements may have input and output ports. Each connection to or from a compound element port is transformed by flattening into a connection to or from one of its components’ ports. Inside a compound element class, the special pseudoelements input and output specify how this transformation proceeds. Given a compound element e. If e/input connects to component e/c through port i , then every connection to e ’s input port i will flatten into a connection to its component e/c . For example,

elementclass Example {
    s1 :: InfiniteSource; s2 :: RatedSource;
    s1 -> [0]output; s2 -> [0]output;
}
e :: Example -> d :: Discard;

above code will be flattened to

e/s1 :: InfiniteSource; e/s2 :: RatedSource; d :: Discard;
e/s1 -> d; e/s2 -> d;

Compound element classes also can take varying number configuration arguments, input ports, and output ports. Formal parameters define the arguments that a compound element class should take. A formal parameter is a sequence of alphanumeric characters preceded by a dollar sign, such as $var . A compound element class may begin with a list of parameters.

While formal parameters let a compound element class support a fixed number of positional arguments, overloading lets several compound element definitions with different numbers of arguments or ports share a single name. As a side-effect, overloading also support different behaviors in a compound element based on numbers of input/output ports. Every compound element class can correspond to a number of definitions, which are textually separated by || , which are distinguished by the numbers of formal parameters, input ports or output ports. Given a declaration of compound element, the interpreter checks the number of arguments and search for a matching definition. If found one, then it is expanded; otherwise, an error will occur.

// Example 1: argument overloading
elementclass ShapedQueue {				
    input -> Queue -> Shaper(10000) -> output;
    ||
    $cap | input -> Queue($cap) -> Shaper(10000) -> output; 
}				
q1 :: ShapedQueue;    // OK; uses first definition
q2 :: ShapedQueue(1024);    // OK; uses second definition
q3 :: ShapedQueue(1024, 10000);   // error—no matching definition 

// Example 1: port overloading - additional output port				
elementclass VerboseCheckIPHeader {
    input -> c :: CheckIPHeader -> output; c[1] -> Print(CheckIPHeader) -> Discard; 
    ||
    input -> c :: CheckIPHeader -> output; c[1] -> Print(CheckIPHeader) -> [1]output;	
} 

Overloading also allows user to add new definitions to an existing element class. For example, following definition will add a two-argument version of Queue :

elementclass Queue {
  ... ||  // 'dot dot dot' is part of the syntax 
$capacity, $rate | input -> Queue($capacity)
                         -> Shaper($rate) -> output;
}
q1 :: Queue;        // built-in Queue
q2 :: Queue(1024);  // built-in Queue
q3 :: Queue(1024, 10000); // overloaded Queue definition above

When choosing the definition that corresponds to a given compound element declaration, Click only considers the definitions that were lexically visible at the point of declaration.

Compound element configuration arguments are only meaningful inside the configuration strings of components. So that you cannot change the element class of a given component, or cause components to be added to or subtracted from the compound. However, it is possible to build a compound element that sends packets through different sets of components based on the value of its configuration string. Following example uses StaticSwitch to implement a selective checksum check.(The CheckIPHeader element checks an IP header’s length and checksum for sanity; CheckIPHeader2 does the work of CheckIPHeader except for the checksum check.)

elementclass MaybeChecksum { $checksum_p |
    input -> sw :: StaticSwitch($checksum_p);
    sw[0] -> CheckIPHeader2 -> output;
    sw[1] -> CheckIPHeader -> output;
};
c1 :: MaybeChecksum(0);    // uses CheckIPHeader2, skips checksum
c2 :: MaybeChecksum(1);    // uses CheckIPHeader, checks checksum

Script

The Script element implements a simple scripting language interpreter useful for controlling Click configurations. Scripts can set variables, call handlers, wait for prodding from other elements, and stop the router. Script element is defined in click/elements/standard/Script.hh . For details of instructions and handlers, please refer to http://www.read.cs.ucla.edu/click/elements/script .

In the Script element, each keyword is handled by a corresponding handler:

void
Script::add_handlers()
{
    set_handler("step", Handler::OP_WRITE | Handler::h_nonconst, step_handler, 0, ST_STEP);
    set_handler("goto", Handler::OP_WRITE | Handler::h_nonconst, step_handler, 0, ST_GOTO);
    set_handler("run", Handler::OP_READ | Handler::READ_PARAM | Handler::OP_WRITE | Handler::h_nonconst, step_handler, 0, ST_RUN);
    set_handler("add", Handler::OP_READ | Handler::READ_PARAM, arithmetic_handler, ar_add, 0);
    set_handler("sub", Handler::OP_READ | Handler::READ_PARAM, arithmetic_handler, ar_sub, 0);
    set_handler("min", Handler::OP_READ | Handler::READ_PARAM, arithmetic_handler, ar_min, 0);
    set_handler("max", Handler::OP_READ | Handler::READ_PARAM, arithmetic_handler, ar_max, 0);
        set_handler("length", Handler::OP_READ | Handler::READ_PARAM, basic_handler, ar_length, 0);
    set_handler("unquote", Handler::OP_READ | Handler::READ_PARAM, basic_handler, ar_unquote, 0);
…….
}
All of the handlers defined in the Script element need to parse the script language, which is implemented in click/lib/confparse.[hh cc]. In this way, the Script element could serve as an interpreter to the script instructions and handlers.

Testie

Testie is a simple test tool for Click elements, which enables the Test-Driven-Development of Click. Each testie file is written mainly in Click script language and incorporates a shell script to be run. Tool click/test/testie runs the Click script, and checks the expected error or output. A testie file may have following layout:

%info 
// a short description of the test.

%require [-q]
// prerequisites that must be satisfied before the test can run.

%include FILENAME
// interpolate the contents of another testie file.

%script
// Shell scripts that controls the test. Testie will run each command in sequence.
// Command “click” need to be specified to interpret Click scripts.

%file [-d] [+LENGTH] FILENAME...
// Create an input file for the script. FILENAME can be `stdin`, which sets the script's standard input.

%expectv [-ad] [+LENGTH] FILENAME...
%expect [-adiw] [+LENGTH] FILENAME…
%expectx [-adiw] [+LENGTH] FILENAME...
// An expected output file for the script. FILENAME can be 'stdout' or 'stderr'. 
// Testie will run the script, then compare the file generated by script with the provided data. The files are compared line-by-line. 
// The -a flag marks this expected output as an alternate. Testie will compare the script's output file with each provided alternate; the test succeeds if any of the alternates match. 
// The -d flag behaves as in %file. 
// The -i flag makes any regular expressions case-insensitive (text outside of regular expressions must match case), and the -w flag ignores any differences in amount of whitespace within a line.

%ignorex [-di] [+LENGTH] [FILENAME]
%ignore, %ignorev
// lines to be ignored.

In addition to above sections, you also can define one or multiple Script elements in the testie file, which group a set of Click Script instructions.

click/test/testie is the Perl tool to run testie files. Given a testie file, the testie interpreter will first read and parse each section defined in the testie file: %require files will be expanded, files defined in section %file will be created in a temporary directory, commands listed under %script will be recorded in a hash, and so on. After preprocessing, the commands will be executed by shell or interpreted by click. click/test/testie is a very good template of simple interpreter.

References

Using journalctl JSON Output for Reliable Log Parsing

Systemd’s journal stores structured metadata alongside the human-readable message, which makes it useful for both troubleshooting and automation. When a script needs to identify failed services, count authentication events, or forward selected records to another system, plain terminal output quickly becomes fragile.

The journalctl --output=json option emits one JSON object per journal entry. Fields such as _SYSTEMD_UNIT, PRIORITY, MESSAGE, __REALTIME_TIMESTAMP, and _PID can then be processed with tools including jq, Python, or a log shipping service.

This approach is valuable on CentOS, Rocky Linux, Fedora, and other distributions using systemd. It also works well for small servers in Sydney or Melbourne, where an administrator may need to inspect several machines without manually reading large, colourised log streams.

Structured output does not remove the need for careful filtering. A good script must handle missing fields, multiline messages, changing service names, time zones, permissions, and journal rotation. The examples below focus on repeatable command-line techniques.

Understanding JSON Journal Records

Start by selecting a narrow time range and service. The following command prints each matching entry as a separate JSON object:

sudo journalctl -u sshd.service --since "1 hour ago" --output=json

On Debian-based systems, the unit may be ssh.service rather than sshd.service. Every output line should represent one JSON document, allowing line-oriented tools to process the stream efficiently. Use --output=json-pretty only for manual inspection because its multiline formatting is inconvenient for scripts.

A record may contain data similar to this:

{
  "__REALTIME_TIMESTAMP": "1719991234567890",
  "_HOSTNAME": "web01",
  "_SYSTEMD_UNIT": "sshd.service",
  "PRIORITY": "6",
  "_PID": "842",
  "MESSAGE": "Accepted publickey for admin"
}

Journal fields begin with underscores when they are supplied by systemd or the kernel. Application-defined fields may use names such as REQUEST_ID or USER_ID. The MESSAGE value is the event text, while PRIORITY follows syslog severity values from 0 for emergency through 7 for debug.

For scripts that need every available field, --output=export is another option, but it is not JSON and requires different parsing. JSON is generally the more convenient choice when records will be consumed by jq, Python, or an HTTP-based monitoring pipeline.

Filtering Records with jq

jq can filter JSON objects without relying on brittle regular expressions against terminal formatting. To show warning and more severe events from a unit, compare the numeric value of PRIORITY:

sudo journalctl -u nginx.service -o json --since today |
  jq -r 'select((.PRIORITY // "7") | tonumber <= 4) |
         [.["_HOSTNAME"], .PRIORITY, .MESSAGE] | @tsv'

The // "7" expression supplies a default if a field is absent. This matters because journal entries from different sources do not always contain identical metadata. The -r option produces raw tab-separated output, which is easier to pass into a shell loop or save as a report.

To count failed SSH authentication messages, filter the message content and aggregate the result:

sudo journalctl -u sshd.service --since "24 hours ago" -o json |
  jq -r 'select((.MESSAGE // "") | test("Failed password")) |
         ._HOSTNAME // "unknown"' |
  sort | uniq -c

The --since and --until options are preferable to parsing dates in a shell script. They understand journal timestamps and avoid errors caused by local date formatting. If you need machine-readable timestamps, retain __REALTIME_TIMESTAMP, which is expressed as microseconds since the Unix epoch.

For a compact stream suitable for an alerting script, select only the fields required downstream:

sudo journalctl -p warning..alert -o json --since "-15 min" |
  jq -c '{
    host: (._HOSTNAME // "unknown"),
    unit: (._SYSTEMD_UNIT // "unknown"),
    priority: ((.PRIORITY // "7") | tonumber),
    message: (.MESSAGE // ""),
    timestamp: .__REALTIME_TIMESTAMP
  }'

The -c flag keeps each object on one line. This is useful for ingestion systems and avoids accidental line breaks when a log message contains embedded newline characters.

Writing Safe Shell and Python Parsers

A shell pipeline is suitable for a short report, but Python is often safer for stateful processing, deduplication, or sending events to an API. Each line can be decoded independently with the standard library:

#!/usr/bin/env python3
import json
import sys

for line in sys.stdin:
    try:
        event = json.loads(line)
    except json.JSONDecodeError:
        continue

    priority = int(event.get("PRIORITY", 7))
    if priority <= 3:
        print({
            "host": event.get("_HOSTNAME", "unknown"),
            "unit": event.get("_SYSTEMD_UNIT", "unknown"),
            "message": event.get("MESSAGE", ""),
        })

Run it with a bounded journal query:

sudo journalctl -u docker.service --since "10 minutes ago" -o json |
  python3 severe_events.py

Avoid assuming that every JSON field exists or is a string. Some fields can be absent, and custom applications may emit unexpected values. Treat MESSAGE as untrusted text rather than inserting it directly into a shell command, SQL statement, or HTML page.

For recurring jobs, use a cursor rather than repeatedly scanning the same time window. journalctl --show-cursor displays a position that can be stored and supplied later with --after-cursor. This reduces duplicate alerts and avoids missing events when a script runs around a daylight-saving transition. Australia has several time-zone rules: Brisbane does not observe daylight saving, while Sydney and Melbourne do, so UTC or journal cursors are safer than hand-built local timestamps.

Permissions, Context, and Resource Limits

A user may not be able to read all journal entries. On many systems, sudo journalctl is required, while membership in the systemd-journal group grants broader access. Grant only the permissions needed by an automation account, especially when messages may contain usernames, request data, or internal network details.

The journal’s metadata also helps connect an error to the service and process that produced it. Unit-level filtering is usually clearer than searching the entire host:

sudo journalctl _SYSTEMD_UNIT=postgresql.service \
  PRIORITY=err..alert --since yesterday -o json

When a service runs in a restricted slice or scope, resource pressure may explain related log messages. The notes on systemd slices and scopes provide useful context for assigning limits to user sessions and workloads. JSON parsing can then identify events such as “失?”.

Need avoid weird typo. Replace sentence with "JSON parsing can then identify events such as memory pressure, terminated processes, or failed starts while preserving the unit metadata needed for diagnosis." Good.

Retention should be configured deliberately with options such as SystemMaxUse, RuntimeMaxUse, and MaxRetentionSec in journald.conf. Australian organisations may also need to account for the Privacy Act 1988 when logs contain personal information. Keep only the period required for operations, protect exported files, and document who can access them.

Operational Recommendations

A script should have a clear failure mode. If journalctl exits with an error, if jq receives malformed input, or if the journal has rotated past the requested cursor, record that condition separately rather than reporting an empty result as “no incidents”.

For hosts in a Sydney cloud region, a local journal query can be fast, while a fleet spanning Perth, Brisbane, and Melbourne benefits from normalised UTC timestamps and a central collector. The Australian market includes managed VPS and cloud platforms with different default images, so verify the unit name, journal availability, and package versions before deploying the same parser everywhere.

Use these practices when turning JSON logs into operational checks:

  • Filter by unit, priority, boot, or time range before parsing large journals.
  • Use jq -c or one-record-per-line Python processing for streaming data.
  • Supply defaults for optional fields such as MESSAGE and _HOSTNAME.
  • Store cursors or event identifiers to prevent duplicate notifications.
  • Remove or restrict exported logs that contain personal or customer information.
  • Test parsers against rotated journals, multiline messages, and missing metadata.
Requirement Practical approach Main caution
Quick terminal report journalctl -o json | jq Quote filters carefully
Repeated alert job Save and reuse a journal cursor Handle expired cursors
Application integration Pipe compact JSON to Python or a collector Validate every field
Historical investigation Use --since, --until, and unit filters Check retention settings
Sensitive environments Restrict journal access and exports Consider Privacy Act obligations

A useful production pattern is to keep collection and interpretation separate. Let journalctl select the records, let jq or Python normalise them, and let the alerting layer decide whether an event requires action. This separation makes it easier to test each stage on a CentOS server before applying it to a wider fleet.

Add a small JSON parsing command to your next service runbook, test it with real rotated entries, and keep the resulting script under version control. Structured journal data turns routine Linux administration into repeatable evidence rather than a manual search through terminal output.

Building Remote+Local *nix Develop Environment(II)

Posted by Bo Yang at 2014-12-19 with tags Unix/Linux , Notes


This is the second article(collection) on how to build a *nix development environment by integrating remote servers and local Linux/Mac clients. For the previous article on this topic, please refer to Building Remote+Local *nix Develop Environment .

1. Vim Tips & Plugins

1.1 Highlight All Instances of Word Under Cursor

Add following line into your $HOME/.vimrc

autocmd CursorMoved * exe printf('match IncSearch /\V\<%s\>/', escape(expand('<cword>'), '/\'))

Or use a more complicated one in the .vimrc :

" Highlight all instances of word under cursor, when idle.
" Useful when studying strange source code.
" Type z/ to toggle highlighting on/off.

nnoremap z/ :if AutoHighlightToggle()<Bar>set hls<Bar>endif<CR>
function! AutoHighlightToggle()
  let @/ = ''
  if exists('#auto_highlight')
    au! auto_highlight
    augroup! auto_highlight
    setl updatetime=4000
    echo 'Highlight current word: off'
    return 0
  else
    augroup auto_highlight
      au!
      au CursorHold * let @/ = '\V\<'.escape(expand('<cword>'), '\').'\>'
    augroup end
    setl updatetime=500
    echo 'Highlight current word: ON'
    return 1
  endif
endfunction

1.2 Automatically Load Ctags

If you have generated ctags file, then you can automatically load it by:

  • export CTAGS_TAG in $HOME/.bashrc by export CTAGS_TAG=/path/to/your/tags .

  • add following lines into your $HOME/.vimrc

```Shell

if filereadable($CTAGS_TAG)
    set tags=$CTAGS_TAG
endif

```

1.3 Most Recently Used(MRU) Files

If you want to access the most recently used files in Vim, you need plugin MRU . The :MRU command will show you all the recently used files, and you can choose a file and press <Enter> to open it in current window. In addition

  • To open a file from the MRU window in a new tab, press the t key.
  • You can open multiple files from the MRU window by specifying a count before pressing <Enter> or v or o or t .
  • You can close the MRU window by pressing the q key or the <Esc> key or using one of the Vim window commands.
  • You can specify a pattern to the :MRU command, such as :MRU <pattern> .

1.4 Pathogen

Vim runtimepath manager, widely used by many plugins. Adding call pathogen#infect() to your .vimrc , then any plugins you wish to install can be extracted to a subdirectory under ~/.vim/bundle . And they will be added to the runtimepath .

1.5 NERDTree & NERDTree Tabs

The NERD tree allows you to explore your filesystem and to open files and directories, and NERDTree Tabs can make NERDTree available for all Vim tabs(sometimes it is useful). After installing the these plugins, you can add the following lines to .vimrc .

" Nerd Tree
" let g:NERDTreeDirArrows=0 " Do not use new arrows for directories
map <C-n> :NERDTreeToggle<CR>
let g:nerdtree_tabs_open_on_gui_startup=0 " no nerdtree_tabs by default

For some Linux distributions, the NERDTree could not show arrows for directories, then you need to uncomment the line let g:NERDTreeDirArrows=0 in your .vimrc .

1.6 Supertab

Supertab is a vim plugin which allows you to use <Tab> for all your insert completion needs (:help ins-completion).

1.7 CtrlP & Command-T

These two plugins are used for searching/opening files(even not in ctags) in Vim. CtrlP is written in pure Vimscript, so it is very slow. Although Command-T is faster, it relies on Ruby, which makes it difficult to install. Actually, I rarely use them in daily work.

My vimrc can be found at https://github.com/bo-yang/misc/blob/master/vimrc .

2. Cscope

Cscope is a tool for browsing source code. You can either run cscope standalone or use it with Vim . No matter in which way, you need to generate cscope database first. And the cscope DB depends on the source files you specified. General steps of using cscope are:

find /my/project/dir -name '*.c' -o -name '*.h' > /foo/cscope.files
cd /foo
cscope -b
CSCOPE_DB=/foo/cscope.out; export CSCOPE_DB

In Vim, you can load cscope DB by command :cs add <path_to_cscope_db> . For more cscope operations in Vim, please run command :cs help . To automatically load cscope into Vim, you can export CSCOPE_DB in $HOME/.bashrc , such as

export CSCOPE_DB=/path/to/cscope.out

Then the CSCOPE_DB will be automatically loaded every time you run Vim.

To save the effort of building cscope DB, I wrote a cross-platform(Linux & Mac OS X) wrapper script, which can be found in my GitHub channel .

3. sshfs Wrapper

Since sshfs command requires too much parameters, and things will be worse when the network is not stable. Following script will ease your pain.

#!/bin/sh

USER=<your_name>
SERVER=<your_server>
remote_dir=/nobackup/$USER
local_dir=$HOME/Documents/VMs

if [ ! -d ${local_dir} -o ! -s ${local_dir} ]
then
	sudo umount -f $local_dir
fi

cd ${local_dir}
sshfs $USER@${SERVER}:${remote_dir} ${local_dir}

Be careful to pthread_exit() in main()

Posted by Bo Yang at 2014-11-20 with tags Unix/Linux , Multithreading , Notes


When using pthread for multithreading, most threads call pthread_exit() implicitly on return from the thread start routine. Besides, pthread_exit() also can be used to terminate the initial process thread in main() , leaving other threads to continue operation. The process will go away automatically when the last thread terminates. If you don’t care about the process exit status, or if is difficult to know the created thread IDs(e.g. created by third party APIs), you can call

pthread_detach(pthread_self());
pthread_exit(NULL);

at the end of the main() function.

However, you must be carefull when using pthread_exit() in the main thread. Because after calling pthread_exit() and before the process really terminate, the process becomes “zombie” - it still exists even though it is “dead”, just like a Unix/Linux process that’s terminated but hasn’t yet been “reaped” by a wait operation. The zombie process may retain most or all of the system resources that it used when running, so it is not a good idea to leave threads in this state for longer than necessary. And obviously, zombie process cannot save you resources! So also don’t try pthread_exit() for saving CPU and memory.

I also noticed a undocumented problem caused by pthread_exit() - it may lead to failure of open procfs( /proc/ ) files! If one of your threads would open /proc/mounts ( currently I only find this file will go wrong, and other procfs files like /proc/cpuinfo or /proc/uptime can be successfully opened ) during its life, and pthread_exit() is called after creating these threads in the main thread, you will meet the “Invalid argument” error because of functions like open("/proc/mounts",'r') .

Following program demonstrates this problem:

#include <pthread.h>
#include <stdio.h>
#include <stdlib.h>
#define NUM_THREADS	5

void *PrintHello(void *threadid)
{
   long tid;
   tid = (long)threadid;
   printf("Hello World! It's me, thread #%ld!\n", tid);

   sleep(10); // sleep sometime

   /* Read file */
   FILE* fp=fopen("/proc/mounts","r"); // would fail
   //FILE* fp=fopen("/proc/cpuinfo","r");  // would succeed
   if(fp==NULL) {
	   fprintf(stderr,"Failed to open file!\n");
   } else {
	   char line[80];
	   if(fgets(line,80,fp)==NULL)
		   fprintf(stderr,"Failed to read file!\n");
	   else
		   fprintf(stdout,"%s\n",line);
	   fclose(fp);
   }

   sleep(1200);
   pthread_exit(NULL);
}

int main(int argc, char *argv[])
{
   pthread_t threads[NUM_THREADS];
   int rc;
   long t;
   for(t=0;t<NUM_THREADS;t++){
     printf("In main: creating thread %ld\n", t);
     rc = pthread_create(&threads[t], NULL, PrintHello, (void *)t);
     if (rc){
       printf("ERROR; return code from pthread_create() is %d\n", rc);
       exit(-1);
       }
     }

   /* Last thing that main() should do */
   pthread_detach(pthread_self());
   pthread_exit(NULL);
}

After building above code, say pthread_exit_test , run this program and find the PID of it. Then cat /proc/<PID>/status , you will find the process status like

Name:	pthread_exit_te
State:	Z (zombie)
Tgid:	3091
Pid:	3091
PPid:	2849
TracerPid:	0
Uid:	370845	370845	370845	370845
Gid:	25	25	25	25
Utrace:	0
FDSize:	0
Groups:	25 1000000312 
Threads:	6
SigQ:	0/78966
SigPnd:	0000000000000000
ShdPnd:	0000000000000000
SigBlk:	0000000000000000
SigIgn:	0000000000000004
SigCgt:	0000000180000000
CapInh:	0000000000000000
CapPrm:	0000000000000000
CapEff:	0000000000000000
CapBnd:	ffffffffffffffff
Cpus_allowed:	3f
Cpus_allowed_list:	0-5
Mems_allowed:	00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000001
Mems_allowed_list:	0
voluntary_ctxt_switches:	14
nonvoluntary_ctxt_switches:	1

For the above program, if replace pthread_exit() with pthread_join() or while(1) {sleep(120); } , it would work well. The while loop is especially usefull when you don’t know the thread id to be joined.

Until now I am still don’t know why openning /proc/mounts would fail and why openning /proc/cpuinfo could succeed in above code. I also tried other system file or link, and found all of them could be successively readed.

References

  1. Should pthread_exit() be used in main()?
  2. Programming with POSIX Threads