Don't reboot, debug!

Transcript

1. 1 Don't reboot, debug! A medic first aid course in debugging your server Joshua Thijssen @JayTaph
4. 4 It's not
5. 4 It is It's not
6. Have you tried turning it off and on again? 5
7. Find the culprit 6
8. Bottleneck Troubleshooting Flowchart (BTF) 7
9. Site is slow or not responding. It’s your DB Bottleneck Troubleshooting Flowchart (BTF) 7
10. 8 Other causes:
11. ➡ Apache / PHP / nginx/php-fpm 8 Other causes:
12. ➡ Apache / PHP / nginx/php-fpm ➡ Monitoring / backup 8 Other causes:
13. ➡ Apache / PHP / nginx/php-fpm ➡ Monitoring / backup ➡ Hanging cron jobs & runaway tools 8 Other causes:
14. ➡ Apache / PHP / nginx/php-fpm ➡ Monitoring / backup ➡ Hanging cron jobs & runaway tools ➡ Connectivity / DNS problems 8 Other causes:
15. 9 Linux 101
16. 9 Linux 101 201
17. 10 Processes
19. 11 ➡ Isolated user space.
20. 11 ➡ Isolated user space. ➡ PID (process id) and state.
21. 11 ➡ Isolated user space. ➡ PID (process id) and state. ➡ Kernel “preempts”, or process yields.
22. 11 ➡ Isolated user space. ➡ PID (process id) and state. ➡ Kernel “preempts”, or process yields. ➡ Multitasking.
24. 12 ➡ R Running or runnable
25. 12 ➡ R Running or runnable ➡ S Interruptible sleep
26. 12 ➡ R Running or runnable ➡ S Interruptible sleep ➡ D Uninterruptible sleep
27. 12 ➡ R Running or runnable ➡ S Interruptible sleep ➡ D Uninterruptible sleep ➡ Z Defunct process (zombies)
30. 14 ➡ Most processes are sleeping.
31. 14 ➡ Most processes are sleeping. ➡ External processes (and the kernel) can “wake up” a process at any time by sending “signals”.
32. 14 ➡ Most processes are sleeping. ➡ External processes (and the kernel) can “wake up” a process at any time by sending “signals”. ➡ Fire signals with “kill”.
34. 15 ➡ Uninterruptible means it won’t handle signals (directly), but waits on its task to finish (it must wake up by itself).
35. 15 ➡ Uninterruptible means it won’t handle signals (directly), but waits on its task to finish (it must wake up by itself). ➡ Used for high-performance loops that needs to focus (like I/O).
36. 15 ➡ Uninterruptible means it won’t handle signals (directly), but waits on its task to finish (it must wake up by itself). ➡ Used for high-performance loops that needs to focus (like I/O). ➡ Still can be preempted by the kernel.
38. 16 ➡ Zombies aren’t bad.
39. 16 ➡ Zombies aren’t bad. ➡ It’s just bad programming or administration that creates zombies.
40. 16 ➡ Zombies aren’t bad. ➡ It’s just bad programming or administration that creates zombies. ➡ But there shouldn’t be many.
41. 17 Load average
43. 18 ➡ 1 minute, 5 minutes, 15 minutes averages
44. 18 ➡ 1 minute, 5 minutes, 15 minutes averages ➡ Calculated as the number of runnable processes (but has more sources nowadays).
45. 18 ➡ 1 minute, 5 minutes, 15 minutes averages ➡ Calculated as the number of runnable processes (but has more sources nowadays). ➡ Depends on number of CPU’s!
46. 19 14:57:22 up 35 days, 18:57, 1 user, load average: 1.52, 0.66, 0.27
47. 19 14:57:22 up 35 days, 18:57, 1 user, load average: 1.52, 0.66, 0.27 ➡ 1.52 average runnable processes in the last minute.
48. 19 14:57:22 up 35 days, 18:57, 1 user, load average: 1.52, 0.66, 0.27 ➡ 1.52 average runnable processes in the last minute. ➡ 0.66 average in 5 minutes
49. 19 14:57:22 up 35 days, 18:57, 1 user, load average: 1.52, 0.66, 0.27 ➡ 1.52 average runnable processes in the last minute. ➡ 0.66 average in 5 minutes ➡ 0.27 average in 15 minutes.
50. 19 14:57:22 up 35 days, 18:57, 1 user, load average: 1.52, 0.66, 0.27 ➡ 1.52 average runnable processes in the last minute. ➡ 0.66 average in 5 minutes ➡ 0.27 average in 15 minutes. ➡ Single CPU: 52% more than it can handle.
51. 19 14:57:22 up 35 days, 18:57, 1 user, load average: 1.52, 0.66, 0.27 ➡ 1.52 average runnable processes in the last minute. ➡ 0.66 average in 5 minutes ➡ 0.27 average in 15 minutes. ➡ Single CPU: 52% more than it can handle. ➡ Quad core system: not doing very much
52. 20 Memory
53. 21 Q: How much memory does this process use? This is REALLY hard question to answer! It depends on many factors!
56. 23 ➡ Virtual memory (VIRT) ➡ Shared memory (SHR SHRD) ➡ Resident memory (RES or RSS) ➡ Swapped memory (SWP, SWAP)
57. 24 (on a 32bit system)
58. 24 ➡ Each process has 4GB memory space usable. (on a 32bit system)
59. 24 ➡ Each process has 4GB memory space usable. ➡ Even if you have less memory installed. (on a 32bit system)
60. 24 ➡ Each process has 4GB memory space usable. ➡ Even if you have less memory installed. ➡ 1GB is reserved for kernel. (on a 32bit system)
61. 25 0x00000000 0xC0000000 0xFFFFFFFF 1 GB 3 GB Virtual memory
62. 25 0x00000000 0xC0000000 0xFFFFFFFF 1 GB 3 GB Virtual memory Translation table
63. 25 0x00000000 0xC0000000 0xFFFFFFFF 1 GB 3 GB Virtual memory Translation table Physical memory
64. 26 Process A Process B Process C Physical Memory
65. 26 Process A Process B Process C Physical Memory & & &
66. 26 Process A Process B Process C Physical Memory & & &
67. 26 Process A Process B Process C Physical Memory & & &
68. 26 Process A Process B Process C Physical Memory & & &
69. ➡ New phone book entries are created. ➡ VIRT will increase. ➡ Allocating memory != using memory. 27 Allocating memory
71. <?php $pid = pcntl_fork(); if ($pid) { echo "Hello, this is the parent process\n"; } else { echo "Hello, this is the child process\n"; } 29
72. 30 Process A
73. 30 Process A fork()
74. 30 Process A Process B fork()
75. 31 C1 B1 A1 C1` B1` A1` A1 B1 C1 Physical Virtual Virtual fork() =>
76. 32 C1 B1 A1 C1` B2 A1` A1 B1 C1 Physical Virtual Virtual fork() => B2
78. 34 How much memory is our server using?
79. $ free -m total used free shared buffers cached Mem: 3963 3500 462 0 722 1263 -/+ buffers/cache: 1515 2448 Swap: 400 20 379 35
80. $ free -m total used free shared buffers cached Mem: 3963 3500 462 0 722 1263 -/+ buffers/cache: 1515 2448 Swap: 400 20 379 35
81. 36 Monitoring
82. 37 ➡ Monitor everything! ➡ System / infrastructure ➡ Application level
85. 40 ➡ With monitoring you have an excellent idea: ➡ what is happening ➡ what happened ➡ what will likely be happening
86. 41 Logging Logging
87. 42 ➡ Log everything from everywhere. ➡ filter later.
88. 43 ➡ syslog ➡ files ➡ mail ➡ slack / hipchat /irc ➡ logstash $ php composer.phar require monolog/monolog
89. 44 System tools
91. TAIL 46
92. 47 ➡ Most daemons will log into /var/log ➡ tail -f /var/log/messages
93. 48 strace
94. 49 ➡ strace displays system calls and signals ➡ Communication between applications and the kernel.
95. 50 $ strace -ff -p <pid> .... socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 20 fcntl(20, F_GETFL) = 0x2 (flags O_RDWR) fcntl(20, F_SETFL, O_RDWR|O_NONBLOCK) = 0 connect(20, {sa_family=AF_INET, sin_port=htons(11211), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) poll([{fd=20, events=POLLOUT}], 1, -1) = 1 ([{fd=20, revents=POLLOUT}]) write(20, "get ez_client1/acls/"..., 44) = 44 read(20, "END\r\n", 8196) = 5 write(20, "get ez_client1/acl/g"..., 40) = 40 read(20, "END\r\n", 8196) = 5 write(20, "quit\r\n", 6) = 6 shutdown(20, 2 /* send and receive */) = 0 close(20) = 0 mkdir("/tmp/smarty", 0777) = -1 EEXIST (File exists) chmod("/tmp/smarty", 0777) = 0 mkdir("/tmp/smarty", 0777) = -1 EEXIST (File exists) chmod("/tmp/smarty", 0777) = 0 access("/userdata/client1/user/templates/nl/block-right-last.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/userdata/client1/user/templates/block-right-last.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/userdata/client1/theme/templates/nl/block-right-last.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/userdata/client1/theme/templates/block-right-last.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/etc/noxlogic/root/themes/ezshopping/templates/nl/block-right-last.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/etc/noxlogic/root/themes/ezshopping/templates/block-right-last.tpl", F_OK) = -1 ENOENT (No such file or directory) mkdir("/tmp/smarty", 0777) = -1 EEXIST (File exists) chmod("/tmp/smarty", 0777) = 0 access("/userdata/client1/user/templates/nl/block-right.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/userdata/client1/user/templates/block-right.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/userdata/client1/theme/templates/nl/block-right.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/userdata/client1/theme/templates/block-right.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/etc/noxlogic/root/themes/ezshopping/templates/nl/block-right.tpl", F_OK) = -1 ENOENT (No such file or directory) access("/etc/noxlogic/root/themes/ezshopping/templates/block-right.tpl", F_OK) = -1 ENOENT (No such file or directory) mkdir("/tmp/smarty", 0777) = -1 EEXIST (File exists)
96. 51 $ strace ping www.google.com .... mprotect(0xb757f000, 4096, PROT_READ) = 0 munmap(0xb76d8000, 44104) = 0 stat64("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=59, ...}) = 0 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 3 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("192.168.178.4")}, 16) = 0 gettimeofday({1347446161, 382120}, NULL) = 0 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}]) send(3, "u\205\1\0\0\1\0\0\0\0\0\0\3www\6google\3com\0\0\1\0\1", 32, MSG_NOSIGNAL) = 32 poll([{fd=3, events=POLLIN}], 1, 5000
97. ➡ strace -e trace=open ➡ strace -ff -p <pid> 52
98. 53 System tap / dtrace System TAP (dtrace)
99. 54 ➡ Unobtrusive probes inside the kernel ➡ Scripts written in D language. ➡ SUN / Solaris only (licensing)
100. 55 ➡ SystemTAP ➡ “GPL” version of dtrace ➡ Awesome, but complex ➡ But you need / want debug info packages
101. probe syscall.open { printf(“%s(%d) open (%s)\n”, execname(), pid(), argstr); } 56 stap syscall.stp
102. 57 ➡ There are some “providers” in the PHP core (zend_dtrace.{c,h,d}) ➡ file / line ➡ function entry / exit ➡ exception caught / thrown
103. Other tools ➡ Valgrind ➡ GDB ➡ XDebug / Profiler ➡ MySQL Proxy / Charles 58
105. Find me on twitter: @jaytaph Find me for development and training: www.noxlogic.nl Find me on email: jthijssen@noxlogic.nl Find me for blogs: www.adayinthelifeof.nl Thank You! https://joind.in/talk/view/15191