UBSAN: Undefined behaviour in net/ipv4/fib_trie.c:1397:22 and UBSAN: Undefined behaviour in ./arch/x86/include/asm/atomic.h:156:2
From: Toralf FÃrster
Date: Tue Jan 26 2016 - 14:45:38 EST
at a 32 nbit KVM image of a Gentoo Linux runniogn v4.5-rc1 - attached is /var/log/messages
--
Toralf, pgp: C4EACDDE 0076E94E
Jan 26 20:39:50 n22kvm-clone syslog-ng[1761]: syslog-ng starting up; version='3.7.2'
Jan 26 20:39:50 n22kvm-clone /etc/init.d/net.eth0[2007]: config_eth0 not specified; defaulting to DHCP
Jan 26 20:39:50 n22kvm-clone dhcpcd[2015]: DUID 00:01:00:01:1b:82:1f:28:52:54:00:bd:b9:51
Jan 26 20:39:50 n22kvm-clone dhcpcd[2015]: eth0: IAID 00:03:16:d8
Jan 26 20:39:50 n22kvm-clone dhcpcd[2015]: eth0: soliciting an IPv6 router
Jan 26 20:39:52 n22kvm-clone kernel: NET: Registered protocol family 17
Jan 26 20:39:51 n22kvm-clone dhcpcd[2015]: eth0: rebinding lease of 192.168.1.142
Jan 26 20:39:56 n22kvm-clone dhcpcd[2015]: eth0: probing for an IPv4LL address
Jan 26 20:39:56 n22kvm-clone dhcpcd[2015]: eth0: DHCP lease expired
Jan 26 20:39:56 n22kvm-clone dhcpcd[2015]: eth0: soliciting a DHCP lease
Jan 26 20:39:58 n22kvm-clone dhcpcd[2015]: eth0: offered 192.168.1.149 from 192.168.1.254
Jan 26 20:39:58 n22kvm-clone dhcpcd[2015]: eth0: probing address 192.168.1.149/16
Jan 26 20:40:00 n22kvm-clone dhcpcd[2015]: eth0: using IPv4LL address 169.254.243.145
Jan 26 20:40:00 n22kvm-clone dhcpcd[2015]: eth0: adding route to 169.254.0.0/16
Jan 26 20:40:00 n22kvm-clone dhcpcd[2015]: eth0: adding default route
Jan 26 20:40:00 n22kvm-clone dhcpcd[2015]: forked to background, child pid 2050
Jan 26 20:40:00 n22kvm-clone ntpdate[2114]: name server cannot be used: Temporary failure in name resolution (-3)
Jan 26 20:40:00 n22kvm-clone /etc/init.d/ntp-client[2096]: ERROR: ntp-client failed to start
Jan 26 20:40:00 n22kvm-clone crond[2138]: (CRON) STARTUP (1.5.0)
Jan 26 20:40:00 n22kvm-clone crond[2138]: (CRON) INFO (RANDOM_DELAY will be scaled with factor 65% if used.)
Jan 26 20:40:00 n22kvm-clone crond[2138]: (CRON) INFO (running with inotify support)
Jan 26 20:40:00 n22kvm-clone haveged[2163]: haveged starting up
Jan 26 20:40:02 n22kvm-clone kernel: ip_tables: (C) 2000-2006 Netfilter Core Team
Jan 26 20:40:02 n22kvm-clone kernel: nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
Jan 26 20:40:01 n22kvm-clone haveged[2164]: haveged: ver: 1.9.1; arch: x86; vend: GenuineIntel; build: (gcc 4.9.3 ITV); collect: 128K
Jan 26 20:40:01 n22kvm-clone haveged[2164]: haveged: cpu: (L4 VC); data: 32K (L2 L4 V); inst: 32K (L2 L4 V); idx: 21/40; sz: 32267/59653
Jan 26 20:40:01 n22kvm-clone haveged[2164]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99827
Jan 26 20:40:01 n22kvm-clone haveged[2164]: haveged: fills: 0, generated: 0
Jan 26 20:40:01 n22kvm-clone rpc.statd[2273]: Version 1.3.1 starting
Jan 26 20:40:01 n22kvm-clone rpc.statd[2273]: Flags: TI-RPC
Jan 26 20:40:01 n22kvm-clone rpc.statd[2273]: Running as root. chown /var/lib/nfs to choose different user
Jan 26 20:40:02 n22kvm-clone kernel: RPC: Registered named UNIX socket transport module.
Jan 26 20:40:02 n22kvm-clone kernel: RPC: Registered udp transport module.
Jan 26 20:40:02 n22kvm-clone kernel: RPC: Registered tcp transport module.
Jan 26 20:40:02 n22kvm-clone kernel: RPC: Registered tcp NFSv4.1 backchannel transport module.
Jan 26 20:40:01 n22kvm-clone sm-notify[2349]: Version 1.3.1 starting
Jan 26 20:40:01 n22kvm-clone ntpd[2412]: ntpd 4.2.8p3@xxxxxxxx Mon Jul 13 13:03:34 UTC 2015 (1): Starting
Jan 26 20:40:01 n22kvm-clone ntpd[2412]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g
Jan 26 20:40:01 n22kvm-clone ntpd[2413]: proto: precision = 1.966 usec (-19)
Jan 26 20:40:01 n22kvm-clone ntpd[2413]: Listen and drop on 0 v6wildcard [::]:123
Jan 26 20:40:01 n22kvm-clone ntpd[2413]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Jan 26 20:40:01 n22kvm-clone ntpd[2413]: Listen normally on 2 lo 127.0.0.1:123
Jan 26 20:40:01 n22kvm-clone ntpd[2413]: Listen normally on 3 eth0 169.254.243.145:123
Jan 26 20:40:01 n22kvm-clone ntpd[2413]: Listen normally on 4 lo [::1]:123
Jan 26 20:40:01 n22kvm-clone ntpd[2413]: Listen normally on 5 eth0 [fe80::5054:ff:fe03:16d8%2]:123
Jan 26 20:40:01 n22kvm-clone ntpd[2413]: Listening on routing socket on fd #22 for interface updates
Jan 26 20:40:01 n22kvm-clone sshd[2442]: Server listening on 0.0.0.0 port 22.
Jan 26 20:40:01 n22kvm-clone sshd[2442]: Server listening on :: port 22.
Jan 26 20:40:03 n22kvm-clone dhcpcd[2050]: eth0: leased 192.168.1.149 for 86400 seconds
Jan 26 20:40:03 n22kvm-clone dhcpcd[2050]: eth0: adding route to 192.168.0.0/16
Jan 26 20:40:03 n22kvm-clone dhcpcd[2050]: eth0: changing default route via 192.168.1.254
Jan 26 20:40:03 n22kvm-clone dhcpcd[2050]: eth0: deleting route to 169.254.0.0/16
Jan 26 20:40:04 n22kvm-clone kernel: ================================================================================
Jan 26 20:40:04 n22kvm-clone kernel: UBSAN: Undefined behaviour in net/ipv4/fib_trie.c:1397:22
Jan 26 20:40:04 n22kvm-clone kernel: shift exponent 32 is too large for 32-bit type 'long unsigned int'
Jan 26 20:40:04 n22kvm-clone kernel: CPU: 1 PID: 2050 Comm: dhcpcd Not tainted 4.5.0-rc1 #1
Jan 26 20:40:04 n22kvm-clone kernel: Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.8.2-0-g33fbe13 by qemu-project.org 04/01/2014
Jan 26 20:40:04 n22kvm-clone kernel: 00000020 00000000 f43918f4 c5bcd78b 00000007 f4391920 f4391904 c5c31bbe
Jan 26 20:40:04 n22kvm-clone kernel: f4391904 c697f7cc f4391984 c5c324dd c6309064 f4391924 00000020 c697f7cc
Jan 26 20:40:04 n22kvm-clone kernel: 00000001 00000286 f3003233 a9fef391 f5b4c2dc 208e95b4 f3883c74 f59c2ce0
Jan 26 20:40:04 n22kvm-clone kernel: Call Trace:
Jan 26 20:40:04 n22kvm-clone kernel: [<c5bcd78b>] dump_stack+0x42/0x67
Jan 26 20:40:04 n22kvm-clone kernel: [<c5c31bbe>] ubsan_epilogue+0xe/0x40
Jan 26 20:40:04 n22kvm-clone kernel: [<c5c324dd>] __ubsan_handle_shift_out_of_bounds+0xdd/0x140
Jan 26 20:40:04 n22kvm-clone kernel: [<c5726e66>] ? __lock_is_held+0x36/0x90
Jan 26 20:40:04 n22kvm-clone kernel: [<c607b7d3>] fib_table_lookup+0x903/0xed0
Jan 26 20:40:04 n22kvm-clone kernel: [<c60746dd>] fib_del_ifaddr+0x75d/0xd50
Jan 26 20:40:04 n22kvm-clone kernel: [<c607462e>] ? fib_del_ifaddr+0x6ae/0xd50
Jan 26 20:40:04 n22kvm-clone kernel: [<c571e27f>] ? __wake_up+0x3f/0x50
Jan 26 20:40:04 n22kvm-clone kernel: [<c6074d21>] fib_inetaddr_event+0x51/0x150
Jan 26 20:40:04 n22kvm-clone kernel: [<c56d9038>] notifier_call_chain+0xa8/0x170
Jan 26 20:40:04 n22kvm-clone kernel: [<c56d91aa>] __blocking_notifier_call_chain+0x4a/0x80
Jan 26 20:40:04 n22kvm-clone kernel: [<c56d91ff>] blocking_notifier_call_chain+0x1f/0x30
Jan 26 20:40:04 n22kvm-clone kernel: [<c6058ee8>] __inet_del_ifa+0x1d8/0x710
Jan 26 20:40:04 n22kvm-clone kernel: [<c605aaf4>] inet_rtm_deladdr+0x194/0x320
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f6af0a>] rtnetlink_rcv_msg+0xba/0x390
Jan 26 20:40:04 n22kvm-clone kernel: [<c572af2b>] ? trace_hardirqs_on+0xb/0x10
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f6ae37>] ? rtnetlink_rcv+0x17/0x30
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f6ae50>] ? rtnetlink_rcv+0x30/0x30
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f9de56>] netlink_rcv_skb+0xc6/0x1c0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f6ae43>] rtnetlink_rcv+0x23/0x30
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f9d1ca>] netlink_unicast+0x1ba/0x320
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f9d778>] netlink_sendmsg+0x448/0x730
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f9d330>] ? netlink_unicast+0x320/0x320
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f02942>] ___sys_sendmsg+0x342/0x670
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f9a19b>] ? netlink_autobind+0x46b/0x770
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f99e0c>] ? netlink_autobind+0xdc/0x770
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f9b948>] ? netlink_bind+0x2a8/0x5f0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f01f84>] ? SYSC_bind+0x64/0xd0
Jan 26 20:40:04 n22kvm-clone kernel: [<c596676c>] ? __fget_light+0x9c/0x170
Jan 26 20:40:04 n22kvm-clone kernel: [<c5966852>] ? __fdget+0x12/0x20
Jan 26 20:40:04 n22kvm-clone kernel: [<c5eff5a8>] ? sockfd_lookup_light+0x18/0xe0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f03858>] __sys_sendmsg+0x38/0x60
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f04796>] SYSC_socketcall+0x906/0xc50
Jan 26 20:40:04 n22kvm-clone kernel: [<c572bb06>] ? __lock_acquire+0x6d6/0x2ea0
Jan 26 20:40:04 n22kvm-clone kernel: [<c572bb06>] ? __lock_acquire+0x6d6/0x2ea0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5681a80>] ? native_restore_fl+0x10/0x10
Jan 26 20:40:04 n22kvm-clone kernel: [<c577a26e>] ? current_kernel_time64+0x8e/0x200
Jan 26 20:40:04 n22kvm-clone kernel: [<c572af2b>] ? trace_hardirqs_on+0xb/0x10
Jan 26 20:40:04 n22kvm-clone kernel: [<c57d8676>] ? __audit_syscall_entry+0x106/0x2a0
Jan 26 20:40:04 n22kvm-clone kernel: [<c56017b2>] ? do_audit_syscall_entry.isra.11+0x72/0xf0
Jan 26 20:40:04 n22kvm-clone kernel: [<c560205f>] ? syscall_trace_enter_phase1+0x11f/0x1f0
Jan 26 20:40:04 n22kvm-clone kernel: [<c57d791a>] ? audit_filter_inodes+0x3a/0x300
Jan 26 20:40:04 n22kvm-clone kernel: [<c560323e>] ? do_fast_syscall_32+0x4e/0x940
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f04bc3>] SyS_socketcall+0x13/0x20
Jan 26 20:40:04 n22kvm-clone kernel: [<c560333f>] do_fast_syscall_32+0x14f/0x940
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f04bb0>] ? SyS_recvmmsg+0xd0/0xd0
Jan 26 20:40:04 n22kvm-clone kernel: [<c61882a1>] sysenter_past_esp+0x42/0x69
Jan 26 20:40:04 n22kvm-clone kernel: ================================================================================
Jan 26 20:40:03 n22kvm-clone dhcpcd[2050]: eth0: removing route to 192.168.0.0/16
Jan 26 20:40:03 n22kvm-clone dhcpcd[2050]: eth0: removing default route via 192.168.1.254
Jan 26 20:40:04 n22kvm-clone kernel: ================================================================================
Jan 26 20:40:04 n22kvm-clone kernel: UBSAN: Undefined behaviour in ./arch/x86/include/asm/atomic.h:156:2
Jan 26 20:40:04 n22kvm-clone kernel: signed integer overflow:
Jan 26 20:40:04 n22kvm-clone kernel: 533473846 + 1904391449 cannot be represented in type 'int'
Jan 26 20:40:04 n22kvm-clone kernel: CPU: 0 PID: 2418 Comm: ntpd Not tainted 4.5.0-rc1 #1
Jan 26 20:40:04 n22kvm-clone kernel: Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.8.2-0-g33fbe13 by qemu-project.org 04/01/2014
Jan 26 20:40:04 n22kvm-clone kernel: 7182b519 00000000 f395fa9c c5bcd78b 00000001 f395facc f395faac c5c31bbe
Jan 26 20:40:04 n22kvm-clone kernel: f395faac c690ddac f395fb30 c5c31f0b c6308e5c f395fad0 0000002b f395faf8
Jan 26 20:40:04 n22kvm-clone kernel: c690ddac 0000002b 00200286 34333335 34383337 02400036 00000027 f395fe9c
Jan 26 20:40:04 n22kvm-clone kernel: Call Trace:
Jan 26 20:40:04 n22kvm-clone kernel: [<c5bcd78b>] dump_stack+0x42/0x67
Jan 26 20:40:04 n22kvm-clone kernel: [<c5c31bbe>] ubsan_epilogue+0xe/0x40
Jan 26 20:40:04 n22kvm-clone kernel: [<c5c31f0b>] handle_overflow+0xbb/0xf0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5bf1750>] ? copy_from_iter+0xc0/0x740
Jan 26 20:40:04 n22kvm-clone kernel: [<c5fc567c>] ? ip_generic_getfrag+0xac/0x110
Jan 26 20:40:04 n22kvm-clone kernel: [<c5c31f52>] __ubsan_handle_add_overflow+0x12/0x20
Jan 26 20:40:04 n22kvm-clone kernel: [<c5faad79>] ip_idents_reserve+0x79/0xa0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5facecf>] __ip_select_ident+0xaf/0x150
Jan 26 20:40:04 n22kvm-clone kernel: [<c5fcea2f>] __ip_make_skb+0x7bf/0x11a0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5fcf748>] ip_make_skb+0xd8/0x100
Jan 26 20:40:04 n22kvm-clone kernel: [<c5fc55d0>] ? ip_reply_glue_bits+0xa0/0xa0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5fc55d0>] ? ip_reply_glue_bits+0xa0/0xa0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f09f10>] ? sock_recv_errqueue+0x300/0x300
Jan 26 20:40:04 n22kvm-clone kernel: [<c604496d>] udp_sendmsg+0x60d/0x15c0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5fc55d0>] ? ip_reply_glue_bits+0xa0/0xa0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f09633>] ? release_sock+0x213/0x3c0
Jan 26 20:40:04 n22kvm-clone kernel: [<c59298d7>] ? rw_copy_check_uvector+0x67/0x1c0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5681a80>] ? native_restore_fl+0x10/0x10
Jan 26 20:40:04 n22kvm-clone kernel: [<c5726e66>] ? __lock_is_held+0x36/0x90
Jan 26 20:40:04 n22kvm-clone kernel: [<c6064976>] ? inet_sendmsg+0x106/0x350
Jan 26 20:40:04 n22kvm-clone kernel: [<c60649e0>] inet_sendmsg+0x170/0x350
Jan 26 20:40:04 n22kvm-clone kernel: [<c6064899>] ? inet_sendmsg+0x29/0x350
Jan 26 20:40:04 n22kvm-clone kernel: [<c6064870>] ? inet_gro_complete+0x410/0x410
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f02870>] ___sys_sendmsg+0x270/0x670
Jan 26 20:40:04 n22kvm-clone kernel: [<c5681a80>] ? native_restore_fl+0x10/0x10
Jan 26 20:40:04 n22kvm-clone kernel: [<c5726e66>] ? __lock_is_held+0x36/0x90
Jan 26 20:40:04 n22kvm-clone kernel: [<c59664d0>] ? __fget+0x190/0x350
Jan 26 20:40:04 n22kvm-clone kernel: [<c59664e4>] ? __fget+0x1a4/0x350
Jan 26 20:40:04 n22kvm-clone kernel: [<c5966363>] ? __fget+0x23/0x350
Jan 26 20:40:04 n22kvm-clone kernel: [<c5966712>] ? __fget_light+0x42/0x170
Jan 26 20:40:04 n22kvm-clone kernel: [<c5966852>] ? __fdget+0x12/0x20
Jan 26 20:40:04 n22kvm-clone kernel: [<c5eff5a8>] ? sockfd_lookup_light+0x18/0xe0
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f03955>] __sys_sendmmsg+0xb5/0x170
Jan 26 20:40:04 n22kvm-clone kernel: [<c56017b2>] ? do_audit_syscall_entry.isra.11+0x72/0xf0
Jan 26 20:40:04 n22kvm-clone kernel: [<c560205f>] ? syscall_trace_enter_phase1+0x11f/0x1f0
Jan 26 20:40:04 n22kvm-clone kernel: [<c57d791a>] ? audit_filter_inodes+0x3a/0x300
Jan 26 20:40:04 n22kvm-clone kernel: [<c560323e>] ? do_fast_syscall_32+0x4e/0x940
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f03a2f>] SyS_sendmmsg+0x1f/0x30
Jan 26 20:40:04 n22kvm-clone kernel: [<c560333f>] do_fast_syscall_32+0x14f/0x940
Jan 26 20:40:04 n22kvm-clone kernel: [<c5f03a10>] ? __sys_sendmmsg+0x170/0x170
Jan 26 20:40:04 n22kvm-clone kernel: [<c61882a1>] sysenter_past_esp+0x42/0x69
Jan 26 20:40:04 n22kvm-clone kernel: ================================================================================
Jan 26 20:40:03 n22kvm-clone dhcpcd[2050]: eth0: no IPv6 Routers available
Jan 26 20:40:04 n22kvm-clone ntpd[2413]: Listen normally on 6 eth0 192.168.1.149:123
Jan 26 20:40:04 n22kvm-clone ntpd[2413]: Deleting interface #3 eth0, 169.254.243.145#123, interface stats: received=0, sent=0, dropped=0, active_time=3 secs
Jan 26 20:40:04 n22kvm-clone ntpd[2413]: 85.25.105.105 local addr 169.254.243.145 -> <null>
Jan 26 20:40:04 n22kvm-clone ntpd[2413]: 213.239.214.143 local addr 169.254.243.145 -> <null>
Jan 26 20:40:04 n22kvm-clone ntpd[2413]: 83.170.1.42 local addr 169.254.243.145 -> <null>
Jan 26 20:40:04 n22kvm-clone ntpd[2413]: 85.25.105.106 local addr 169.254.243.145 -> <null>
Jan 26 20:40:26 n22kvm-clone login[2468]: pam_unix(login:auth): authentication failure; logname=LOGIN uid=0 euid=0 tty=/dev/tty1 ruser= rhost= user=root
Jan 26 20:40:29 n22kvm-clone login[2468]: FAILED LOGIN (1) on '/dev/tty1' FOR 'root', Authentication failure
Jan 26 20:40:31 n22kvm-clone login[2468]: pam_unix(login:session): session opened for user root by LOGIN(uid=0)
Jan 26 20:40:31 n22kvm-clone login[2525]: ROOT LOGIN on '/dev/tty1'
Jan 26 20:41:32 n22kvm-clone sshd[2530]: Accepted publickey for root from 192.168.1.254 port 36454 ssh2: RSA SHA256:shLZ2PU4MGlaz4JZ5jSWXVp/waiXgKtEdH/fOWuvzdQ
Jan 26 20:41:32 n22kvm-clone sshd[2530]: pam_unix(sshd:session): session opened for user root by (uid=0)
Jan 26 20:41:32 n22kvm-clone sshd[2530]: Received disconnect from 192.168.1.254: 11: disconnected by user
Jan 26 20:41:32 n22kvm-clone sshd[2530]: Disconnected from 192.168.1.254
Jan 26 20:41:32 n22kvm-clone sshd[2530]: pam_unix(sshd:session): session closed for user root
Jan 26 20:42:07 n22kvm-clone sshd[2535]: Accepted publickey for root from 192.168.1.254 port 36456 ssh2: RSA SHA256:shLZ2PU4MGlaz4JZ5jSWXVp/waiXgKtEdH/fOWuvzdQ
Jan 26 20:42:07 n22kvm-clone sshd[2535]: pam_unix(sshd:session): session opened for user root by (uid=0)
Jan 26 20:42:07 n22kvm-clone sshd[2535]: Received disconnect from 192.168.1.254: 11: disconnected by user
Jan 26 20:42:07 n22kvm-clone sshd[2535]: Disconnected from 192.168.1.254
Jan 26 20:42:07 n22kvm-clone sshd[2535]: pam_unix(sshd:session): session closed for user root
Jan 26 20:42:14 n22kvm-clone sshd[2540]: Accepted publickey for root from 192.168.1.254 port 36458 ssh2: RSA SHA256:shLZ2PU4MGlaz4JZ5jSWXVp/waiXgKtEdH/fOWuvzdQ
Jan 26 20:42:14 n22kvm-clone sshd[2540]: pam_unix(sshd:session): session opened for user root by (uid=0)