Matthai Posted August 22, 2017 Posted August 22, 2017 Hi, I have noticed very strange behaviour of my OrangePi PC Plus. Device is connected to internet via Wifi. After successful connection, device is connected to VPN service. A cron script is checking every minute if VPN is working, and if not, it is restarting connection. On every hour, Network Manager is being restarted (you will see why is that so later). On every minute NTP is querryed for time synchronisation. After VPN restart or rebooting of device, device sends an e-mail notification via GMail. On eth0 there is DHCP server running (dnsmasq), which is providing internet to a device connected to OrangePi. So basically, you plug in ethernet cable to OrangePi, get DHCP and connection directly to VPN. At the same time, I am doing port forwarding to this device, so it is directly accessible through VPN network (and OrangePi is some sort of a "relay"). Additionally, OrangePi has connected USB webcam and Arduino with sensors. Video stream and sensor data are displayed via web server running on OrangePi. So this is a setup. And the problem is, device is losing VPN connection all the time (and this connection cannot be restored back) and gets rebooted several times a day. Sometimes port forwarding works, I can also access sensor data via web interface, but cannot connect to it via ssh (all this through VPN netwrk). Nmap shows ssh is open, but connection just times out. However, I found out that /var/log/syslog contains very strange entries. For instance: Aug 22 11:23:41 localhost cron[580]: sendmail: Cannot open smtp.gmail.com:587 Aug 22 11:23:41 localhost sSMTP[8377]: Cannot open smtp.gmail.com:587 Aug 22 11:23:41 localhost CRON[8221]: (root) MAIL (mailed 204 bytes of output but got status 0x0001 from MTA#012) Aug 22 11:23:41 localhost sSMTP[8378]: Unable to locate smtp.gmail.com Aug 22 11:23:41 localhost sSMTP[8378]: Cannot open smtp.gmail.com:587 Aug 22 11:23:41 localhost cron[580]: sendmail: Cannot open smtp.gmail.com:587 Aug 22 11:23:41 localhost CRON[8246]: (root) MAIL (mailed 204 bytes of output but got status 0x0001 from MTA#012) Aug 22 11:23:59 localhost kernel: [ 9200.920004] INFO: rcu_sched self-detected stall on CPU Aug 22 11:23:59 localhost kernel: [ 9200.920004] 0: (778153 ticks this GP) idle=719/140000000000001/0 Aug 22 11:23:59 localhost kernel: [ 9200.920004] (t=824991 jiffies) Aug 22 11:23:59 localhost kernel: [ 9200.920004] Backtrace for cpu 0 (current): Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0016a20>] (unwind_backtrace+0x0/0xe8) from [<c0615d20>] (dump_stack+0x20/0x24) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0615d20>] (dump_stack+0x20/0x24) from [<c0013ff0>] (smp_send_all_cpu_backtrace+0x74/0xe0) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0013ff0>] (smp_send_all_cpu_backtrace+0x74/0xe0) from [<c000f4fc>] (arch_trigger_all_cpu_backtrace+0x18/0x1c) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c000f4fc>] (arch_trigger_all_cpu_backtrace+0x18/0x1c) from [<c00aab70>] (__rcu_pending+0xb8/0x434) Aug 22 11:23:59 localhost kernel: [ 9200.980009] INFO: rcu_sched detected stalls on CPUs/tasks: Aug 22 11:23:59 localhost kernel: [ 9200.980019] 0: (778153 ticks this GP) idle=719/140000000000001/0 � Aug 22 11:23:59 localhost kernel: [ 9200.980025] (detected by 2, t=824996 jiffies) Aug 22 11:23:59 localhost kernel: [ 9200.980032] INFO: Stall ended before state dump start Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c00aab70>] (__rcu_pending+0xb8/0x434) from [<c00abfdc>] (rcu_check_callbacks+0x180/0x250) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c00abfdc>] (rcu_check_callbacks+0x180/0x250) from [<c0039390>] (update_process_times+0x48/0x78) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0039390>] (update_process_times+0x48/0x78) from [<c00763e0>] (tick_sched_timer+0xac/0xec) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c00763e0>] (tick_sched_timer+0xac/0xec) from [<c004deb4>] (__run_hrtimer+0xe4/0x260) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c004deb4>] (__run_hrtimer+0xe4/0x260) from [<c004ea24>] (hrtimer_interrupt+0x14c/0x2a0) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c004ea24>] (hrtimer_interrupt+0x14c/0x2a0) from [<c0014a14>] (arch_timer_handler+0x38/0x48) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0014a14>] (arch_timer_handler+0x38/0x48) from [<c00a6c80>] (handle_percpu_devid_irq+0xb4/0x180) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c00a6c80>] (handle_percpu_devid_irq+0xb4/0x180) from [<c00a3220>] (generic_handle_irq+0x30/0x40) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c00a3220>] (generic_handle_irq+0x30/0x40) from [<c000ef54>] (handle_IRQ+0x8c/0xbc) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c000ef54>] (handle_IRQ+0x8c/0xbc) from [<c000853c>] (gic_handle_irq+0x4c/0x6c) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c000853c>] (gic_handle_irq+0x4c/0x6c) from [<c000db40>] (__irq_svc+0x40/0x74) Aug 22 11:23:59 localhost kernel: [ 9200.920004] Exception stack(0xedae9818 to 0xedae9860) Aug 22 11:23:59 localhost kernel: [ 9200.920004] 9800: 600f0113 00000000 Aug 22 11:23:59 localhost kernel: [ 9200.920004] 9820: 00000001 00000001 edae8000 ee06dc5c ee06dc5c ed20e900 ee06dd0c 00000008 Aug 22 11:23:59 localhost kernel: [ 9200.920004] 9840: ed663b48 edae9874 edae9878 edae9860 c061da5c c061da20 200f0113 ffffffff Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c000db40>] (__irq_svc+0x40/0x74) from [<c061da20>] (__raw_spin_lock_irqsave+0x84/0xa8) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c061da20>] (__raw_spin_lock_irqsave+0x84/0xa8) from [<c061da5c>] (_raw_spin_lock_irqsave+0x18/0x1c) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c061da5c>] (_raw_spin_lock_irqsave+0x18/0x1c) from [<c04f3e44>] (skb_dequeue+0x24/0x74) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04f3e44>] (skb_dequeue+0x24/0x74) from [<c04f4a78>] (skb_queue_purge+0x20/0x34) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04f4a78>] (skb_queue_purge+0x20/0x34) from [<c0522fe4>] (netlink_sock_destruct+0x50/0xc0) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0522fe4>] (netlink_sock_destruct+0x50/0xc0) from [<c04f2330>] (__sk_free+0x28/0x188) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04f2330>] (__sk_free+0x28/0x188) from [<c04f24d0>] (sk_free+0x40/0x44) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04f24d0>] (sk_free+0x40/0x44) from [<c0524284>] (netlink_release+0x244/0x260) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0524284>] (netlink_release+0x244/0x260) from [<c04edca4>] (sock_release+0x30/0xe4) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04edca4>] (sock_release+0x30/0xe4) from [<c04edd88>] (sock_close+0x30/0x3c) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04edd88>] (sock_close+0x30/0x3c) from [<c0120084>] (fput+0x120/0x228) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0120084>] (fput+0x120/0x228) from [<c011d358>] (filp_close+0x80/0x8c) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c011d358>] (filp_close+0x80/0x8c) from [<c002d970>] (put_files_struct+0xa4/0xfc) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c002d970>] (put_files_struct+0xa4/0xfc) from [<c002da68>] (exit_files+0x4c/0x50) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c002da68>] (exit_files+0x4c/0x50) from [<c002e1d8>] (do_exit+0x25c/0x794) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c002e1d8>] (do_exit+0x25c/0x794) from [<c0012924>] (die+0x344/0x420) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0012924>] (die+0x344/0x420) from [<c0615f10>] (__do_kernel_fault.part.0+0x64/0x84) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c0615f10>] (__do_kernel_fault.part.0+0x64/0x84) from [<c001b354>] (do_page_fault+0x2f0/0x344) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c001b354>] (do_page_fault+0x2f0/0x344) from [<c001b488>] (do_translation_fault+0x2c/0xb8) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c001b488>] (do_translation_fault+0x2c/0xb8) from [<c00083a8>] (do_DataAbort+0x44/0xa8) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c00083a8>] (do_DataAbort+0x44/0xa8) from [<c000dad8>] (__dabt_svc+0x38/0x60) Aug 22 11:23:59 localhost kernel: [ 9200.920004] Exception stack(0xedae9c30 to 0xedae9c78) Aug 22 11:23:59 localhost kernel: [ 9200.920004] 9c20: 00000000 ee06dc50 00000001 edae9cd8 Aug 22 11:23:59 localhost kernel: [ 9200.920004] 9c40: ee06dc00 00000000 ee06dc5c edae8000 200f0013 eeb7dc00 edae9cdc edae9ccc Aug 22 11:23:59 localhost kernel: [ 9200.920004] 9c60: 00000000 edae9c78 c061da5c c04f907c 600f0093 ffffffff Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c000dad8>] (__dabt_svc+0x38/0x60) from [<c04f907c>] (__skb_recv_datagram+0x180/0x330) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04f907c>] (__skb_recv_datagram+0x180/0x330) from [<c04f926c>] (skb_recv_datagram+0x40/0x48) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04f926c>] (skb_recv_datagram+0x40/0x48) from [<c05232cc>] (netlink_recvmsg+0x54/0x364) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c05232cc>] (netlink_recvmsg+0x54/0x364) from [<c04ed2e4>] (sock_recvmsg+0xc8/0xf0) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04ed2e4>] (sock_recvmsg+0xc8/0xf0) from [<c04ee47c>] (___sys_recvmsg.part.5+0xdc/0x188) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04ee47c>] (___sys_recvmsg.part.5+0xdc/0x188) from [<c04ef5d0>] (__sys_recvmsg+0x60/0x84) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04ef5d0>] (__sys_recvmsg+0x60/0x84) from [<c04ef60c>] (sys_recvmsg+0x18/0x1c) Aug 22 11:23:59 localhost kernel: [ 9200.920004] [<c04ef60c>] (sys_recvmsg+0x18/0x1c) from [<c000df60>] (ret_fast_syscall+0x0/0x30) Aug 22 11:23:59 localhost kernel: [ 9200.920004] Aug 22 11:23:59 localhost kernel: [ 9200.920004] sending IPI to all other CPUs: Aug 22 11:23:59 localhost kernel: [ 9201.474915] IPI backtrace for cpu 2 Aug 22 11:23:59 localhost kernel: [ 9201.478780] Aug 22 11:23:59 localhost kernel: [ 9201.480003] Pid: 0, comm: swapper/2 Aug 22 11:23:59 localhost kernel: [ 9201.480003] CPU: 2 Tainted: G D (3.4.113-sun8i #18) Aug 22 11:23:59 localhost kernel: [ 9201.480003] PC is at default_idle+0x34/0x3c Aug 22 11:23:59 localhost kernel: [ 9201.480003] LR is at default_idle+0x30/0x3c Aug 22 11:23:59 localhost kernel: [ 9201.480003] pc : [<c000f2dc>] lr : [<c000f2d8>] psr: 600f0013 Aug 22 11:23:59 localhost kernel: [ 9201.480003] sp : ef0edfb0 ip : ef0edfc0 fp : ef0edfbc Aug 22 11:23:59 localhost kernel: [ 9201.480003] r10: 00000000 r9 : 410fc075 r8 : 4000406a Aug 22 11:23:59 localhost kernel: [ 9201.480003] r7 : c0992964 r6 : ef0ec000 r5 : 00000002 r4 : ef0ec000 Aug 22 11:23:59 localhost kernel: [ 9201.480003] r3 : 00000000 r2 : 0000000f r1 : c094430c r0 : c13edb38 Aug 22 11:23:59 localhost kernel: [ 9201.480003] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment kernel Aug 22 11:23:59 localhost kernel: [ 9201.480003] Control: 10c5387d Table: 6e0bc06a DAC: 00000015 Aug 22 11:23:59 localhost kernel: [ 9201.480003] Aug 22 11:23:59 localhost kernel: [ 9201.480003] PC: 0xc000f25c: Aug 22 11:23:59 localhost kernel: [ 9201.480003] f25c e1a00005 e59f300c e2833480 e12fff33 e7f001f2 c0943d2c c061df5c e1a0c00d Aug 22 11:23:59 localhost kernel: [ 9201.480003] f27c e92dd800 e24cb004 e52de004 e8bd4000 f57ff05f e3a02001 e3a01000 e59f0004 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f29c eb01b25d e89da800 c000f4cc e1a0c00d e92dd800 e24cb004 e52de004 e8bd4000 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f2bc e59f301c e5933058 e3530000 0a000001 e12fff33 ea000000 eb003d31 f1080080 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f2dc e89da800 c09926c8 e1a0c00d e92dd830 e24cb004 e52de004 e8bd4000 e1a0300d Aug 22 11:23:59 localhost kernel: [ 9201.480003] f2fc e1a00001 e3c31d7f e3c1103f e5d14051 e5d13052 e1944003 0a000002 e3a02074 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f31c e2811e12 eb0bea36 e2940000 13a00001 e89da830 e1a0c00d e92dd870 e24cb004 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f33c e24dd054 e52de004 e8bd4000 e1a05000 e1a06001 e24b0064 e3a01048 e1a04002 Aug 22 11:23:59 localhost kernel: [ 9201.480003] Aug 22 11:23:59 localhost kernel: [ 9201.480003] LR: 0xc000f258: Aug 22 11:23:59 localhost kernel: [ 9201.480003] f258 e12fff33 e1a00005 e59f300c e2833480 e12fff33 e7f001f2 c0943d2c c061df5c Aug 22 11:23:59 localhost kernel: [ 9201.480003] f278 e1a0c00d e92dd800 e24cb004 e52de004 e8bd4000 f57ff05f e3a02001 e3a01000 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f298 e59f0004 eb01b25d e89da800 c000f4cc e1a0c00d e92dd800 e24cb004 e52de004 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f2b8 e8bd4000 e59f301c e5933058 e3530000 0a000001 e12fff33 ea000000 eb003d31 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f2d8 f1080080 e89da800 c09926c8 e1a0c00d e92dd830 e24cb004 e52de004 e8bd4000 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f2f8 e1a0300d e1a00001 e3c31d7f e3c1103f e5d14051 e5d13052 e1944003 0a000002 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f318 e3a02074 e2811e12 eb0bea36 e2940000 13a00001 e89da830 e1a0c00d e92dd870 Aug 22 11:23:59 localhost kernel: [ 9201.480003] f338 e24cb004 e24dd054 e52de004 e8bd4000 e1a05000 e1a06001 e24b0064 e3a01048 Aug 22 11:23:59 localhost kernel: [ 9201.480003] Aug 22 11:23:59 localhost kernel: [ 9201.480003] SP: 0xef0edf30: Aug 22 11:23:59 localhost kernel: [ 9201.480003] df30 410fc075 00000000 ef0edf64 ef0edf48 c0008554 c0014068 c000f2dc 600f0013 Aug 22 11:23:59 localhost kernel: [ 9201.480003] df50 ffffffff ef0edf9c ef0edfbc ef0edf68 c000db40 c00084fc c13edb38 c094430c Aug 22 11:23:59 localhost kernel: [ 9201.480003] df70 0000000f 00000000 ef0ec000 00000002 ef0ec000 c0992964 4000406a 410fc075 Aug 22 11:23:59 localhost kernel: [ 9201.480003] df90 00000000 ef0edfbc ef0edfc0 ef0edfb0 c000f2d8 c000f2dc 600f0013 ffffffff Aug 22 11:23:59 localhost kernel: [ 9201.480003] dfb0 ef0edfd4 ef0edfc0 c000f694 c000f2b4 c0954cd4 00000002 ef0edff4 ef0edfd8 Aug 22 11:23:59 localhost kernel: [ 9201.480003] dfd0 c0612c1c c000f5f8 6f0a406a 00000015 10c0387d c0992964 00000000 ef0edff8 Aug 22 11:23:59 localhost kernel: [ 9201.480003] dff0 40612234 c0612b20 efafbfdf 7fdfbbff 00000000 00000002 00000000 ef0eb240 Aug 22 11:23:59 localhost kernel: [ 9201.480003] e010 c094b3c0 00000002 00000015 c13ef780 ef0eb240 ef0ee000 ef0eb800 13c11fb9 Aug 22 11:23:59 localhost kernel: [ 9201.480003] and so on... And even that (please note strange characters at the end): Aug 22 11:24:01 localhost kernel: [ 9202.438909] [<c000db40>] (__irq_svc+0x40/0x74) from [<c000f2dc>] (default_idle+0x34/0x3c) Aug 22 11:24:01 localhost kernel: [ 9202.438909] [<c000f2dc>] (default_idle+0x34/0x3c) from [<c000f694>] (cpu_idle+0xa8/0xf4) Aug 22 11:24:01 localhost kernel: [ 9202.438909] [<c000f694>] (cpu_idle+0xa8/0xf4) from [<c0612c1c>] (secondary_start_kernel+0x108/0x12c) Aug 22 11:24:01 localhost kernel: [ 9202.438909] [<c0612c1c>] (secondary_start_kernel+0x108/0x12c) from [<40612234>] (0x40612234) Aug 22 11:24:01 localhost CRON[8391]: (root) CMD (/etc/openvpn/checkvpn.sh) Aug 22 11:24:01 localhost root: CHECKVPN: Starting script... NTP querying. Aug 22 11:24:21 localhost ntpdate[8394]: Can't find host goodtime.ijs.si: Name or service not known (-2) Aug 22 11:24:21 localhost ntpdate[8394]: no servers can be used, exiting Aug 22 11:24:21 localhost root: CHECKVPN: contacting VPN... Aug 22 11:24:30 localhost root: CHECKVPN: VPN connection lost, resetting... Aug 22 11:24:59 localhost kernel: [ 9261.000004] INFO: rcu_sched self-detected stall on CPU Aug 22 11:24:59 localhost kernel: [ 9261.000004] 0: (783818 ticks this GP) idle=719/140000000000001/0 Aug 22 11:24:59 localhost kernel: [ 9261.000004] (t=830999 jiffies) Aug 22 11:24:59 localhost kernel: [ 9261.000004] Backtrace for cpu 0 (current): Aug 22 11:24:59 localhost kernel: [ 9261.000004] [<c0016a20>] (unwind_backtrace+0x0/0xe8) from [<c0615d20>] (dump_stack+0x20/0x24) Aug 22 11:24:59 localhost kernel: [ 9261.030028] INFO: rcu_sched detected stalls on CPUs/tasks: Aug 22 11:24:59 localhost kernel: [ 9261.030045] 0: (783818 ticks this GP) idle=719/140000000000001/0 \ECݦ\EDpݦ\ED\E0\D8 \C0\C0�\95\C0H\DB>\C1\93��`\B4K\94\C0\C0�\95\C0\C0�\95\C0\C0@\92\C0\ACݦ\ED\98ݦ\EDpaa\C0\\DAa\C0\C0�\95\C0|\AC Aug 22 11:24:59 localhost kernel: [ 9261.030053] \C0\C0�\95\C0H\DB>\C1\C0�\95\C0H\DB>\C1\F4ݦ\ED\C0ݦ\ED\C0\AC Aug 22 11:24:59 localhost kernel: [ 9261.030056] \C0\F8\96 Aug 22 11:24:59 localhost kernel: [ 9261.030058] \C0�ަ\ED Aug 22 11:24:59 localhost kernel: [ 9261.030061] (detected by 2, t=831002 jiffies) Aug 22 11:24:59 localhost kernel: [ 9261.030069] INFO: Stall ended before state dump start Aug 22 11:24:59 localhost kernel: [ 9261.000004] [<c0615d20>] (dump_stack+0x20/0x24) from [<c0013ff0>] (smp_send_all_cpu_backtrace+0x74/0xe0) Aug 22 11:24:59 localhost kernel: [ 9261.000004] [<c0013ff0>] (smp_send_all_cpu_backtrace+0x74/0xe0) from [<c000f4fc>] (arch_trigger_all_cpu_backtrace+0x18/0x1c) Any idea what is going on? Kernel problem? Hardware problem? Thank you for any answers and ideas...
Recommended Posts