SpringCloud Service Governance (thirty-one) Online troubleshooting

Online problems are different from development-time bugs and are related to the runtime environment, stress, concurrency, and specific business. For online problems it is important to collect the necessary information using the tools available in the online environment to locate the problem.

1

Common problems with services

The online problems of all Java services boil down to four aspects in terms of system representation: CPU, memory, disk, and network. Such as sudden spikes in CPU usage, memory overflow (leak), full disk, abnormal network traffic, FullGC, etc. Based on these phenomena, we can classify online problems into two categories: system exceptions and business service exceptions.

• A system exception

Common system exceptions include high CPU usage, high CPU context switchover frequency, full disk, frequent disk I/O, low available memory for a long time (oom killer), abnormal network traffic (too many connections), and so on. You can use tools such as TOP (CPU), free (memory), DF (disk), dstat (network traffic), Strace (underlying system call), pstack, and vmstat to obtain system exception data. Common service exceptions include high PV volume, abnormal service invocation time, thread deadlocks, multithreading concurrency, frequent Full GC, and scanning for security attacks

2

Problem orientation

We generally adopt the elimination method, from external investigation to internal investigation to locate online service problems.

• First we need to troubleshoot problems that may be caused by other processes (besides the main process)
• Secondly, troubleshoot the faults that may be caused by service applications
• Finally, you can consider whether the fault is caused by the carrier or cloud service provider

Positioning process

• Process for troubleshooting system faults

• Service application troubleshooting process

A common performance analysis tool for Linux

Common performance analysis tools used in Linux include TOP (CPU), DF (disk), free (memory), Dstat (network traffic), vmstat, pstack, and strace (low-level system call).

• CPU

CPU is an important monitoring indicator of the system and can analyze the overall running status of the system. Monitoring indicators generally include running queues,

CPU

Usage and context switching.

The top command is a common CPU performance analysis tool in Linux. It displays the resource usage of each process in the system in real time and is often used to analyze server performance

The top command displays the CPU usage of each process in ascending order. Load Average displays the system Load averages of the last 1 minute, 5 minutes, and 15 minutes. The values in the preceding figure are 2.46, 1.96, and 1.99, respectively. We tend to focus on the process with the highest CPU usage, which is normally our main application process. Line 7 below: Monitoring the status of each process.

PID: indicates the id of a process. USER: indicates the process owner. PR: indicates the priority of a process. A negative value indicates the high priority, and a positive value indicates the low priority. VIRT: Total virtual memory used by a process, in KB. VIRT=SWAP+RES RES: physical memory size used by a process that has not been swapped out (unit: KB). RES=CODE+DATA SHR: indicates the shared memory size (unit: KB). S: indicates the process status. D= Uninterruptable sleep R= Running S= sleep T= Tracing/stopping Z= zombie process %CPU: percentage of CPU usage since the last update %MEM: percentage of physical memory used by the process TIME+ : Total CPU time used by a process, expressed in 1/100 second COMMAND: indicates the name of a processCopy the code

• memory

Memory is an important reference for troubleshooting online problems, and memory problems are often the insight factor for higher CPU utilization.

System memory: Free is to display the current memory usage, and -m means M bytes to display the content.

free -m
Copy the code

Some parameters are described as follows: Total Total memory: 3790M Used Used memory: 1880M Free Free memory: 118M Shared Used memory, always 0

• disk

When the disk is full, system services may become unavailable

df -h
Copy the code

du -m /path
Copy the code

• network

The dstat command can integrate vmstat, iostat, netstat, and other tasks.

Dstat -c CPU status -d Disk read/write status -n Network status -l Displays system load status -m Displays memory status -p displays system process information -r displays system I/O statusCopy the code

• other

The vmstat:

vmstat 2 10 -t
Copy the code

Vmstat stands for Virtual Meomory Statistics. Vmstat is a real-time system monitoring tool. The command accesses this data by using the knlist subroutine and the /dev/kmen pseudo-device driver, and the output is printed directly to the screen.

Run the vmstat 2 10 -t command to check the I/O status. The first parameter is the sampling interval in seconds, and the second parameter is the number of sampling times.

R represents the run queue (that is, how many processes are actually allocated to the CPU), and B represents blocked processes. SWPD The amount of virtual memory that has been used, if greater than 0, indicates that your machine is running out of physical memory. Free The size of the free physical memory. My machine has a total of 4G memory, with about 120M remaining. Buff Linux/Unix system is used to store the contents of the directory, permissions, etc., cache, my native use about 40 + Mcache file cache si column represents by disk call to memory, is the amount of memory into memory swap; The so column indicates the amount of memory transferred from the memory to the disk, that is, the amount of memory transferred from the memory swap area. Generally, the values of SI and SO are 0. If the values of SI and SO are not 0 for a long time, the system memory is insufficient and you need to consider whether to increase the system memory. Bi Total data read from the block device (Disk read) (KB per second) BO Total data write from the block device (disk write) (KB per second) In random disk read and write operations, the larger the two values are (the value exceeds 1024 KB), the larger the CPU waits in I/O waiting. The bi+ BO reference value is 1000. If the value of WA exceeds 1000, it indicates the I/O performance bottleneck of the system disk. In Number of CPU interrupts per second, including time interrupts CSCopy the code

Strace: Strace is often used to track system calls and signals received while a process is executing.

Strace -cp tid strace -t -p tid -t Displays the time consumed by each call -p pid Tracks the specified process pid. -v Displays all system calls. Some calls about environment variables, status, I/O, etc., are frequently used, and are not output by default. -v Displays strace version information.Copy the code

JVM problem location tool

The bin directory in the JDK installation directory provides many valuable command-line tools by default. Each gadget is relatively small because it is simply a wrapper around the JDK \lib\tools.jar.

The most common commands for locating faults include JPS (process), jmap (memory), jstack (thread), and jinfo (parameter).

• JPS: Queries information about all JAVA processes on the current machine
• Jmap: Outputs memory information for a Java process (such as which objects are generated and how many are generated)
• Jstack: Prints thread stack information for a Java thread
• Jinfo: Used to view configuration parameters for the JVM
• The JPS command

JPS displays the ids of all processes started by the current user. When a fault or problem is detected online, JPS can be used to quickly locate the corresponding Java process ID.

The jps-l-m-m-l-l argument is used to print the full path of the main boot classCopy the code

Of course, we can also use Linux to query the process status command, for example:

ps -ef | grep tomcat
Copy the code

We can also quickly obtain the Tomcat service process ID.

• Jmap command

  Jmap-heap PID output current process JVM heap new generation, old generation, persistent generation, etc. GC information such as the algorithm using jmap – histo: live {pid} | head -n 10 output current process in memory all the size of the object contains jmap – dump: the format = b, the file = / usr/local/logs/GC/dump hprof {PID} in binary output file current memory heap, and then can be imported into MAT and other tools

JMap (Java Memory Map) is a tool that can output all objects in Memory, even the heap in the VM, as binary output to text.

Jmap – heap pid:

Jmap-heap PID Displays information about the current process JVM heap, such as new generation, old age, persistent generation, and the algorithm used by GCCopy the code

Jmap allows you to view information such as memory allocation and usage of JVM processes, GC algorithms used, and so on.

Jmap – histo: live {pid} | head -n 10:

Jmap - histo: live {pid} | head -n 10 output current process in memory all the size of the object containsCopy the code

Instances and bytes are displayed in the memory of the current process. If the number and size of a service object are abnormal, memory leaks may occur or improper service design may occur.

Jmap – dump:

jmap -dump:format=b,file=/usr/local/logs/gc/dump.hprof {pid}
Copy the code

-dump:formate=b,file= Outputs the heap information of the current memory in binary to the corresponding file. Then, you can use memory analysis tools such as MAT to analyze the current memory information in depth.

-xx :+Heap Dump On Out Of Memory Error OOM To ensure that the JVM can save and Dump the current Memory image when the application occurs OOM. Of course, if you decide to dump memory manually, the dump operation takes up a certain amount of CPU time, memory resources, disk resources, etc., so it has a certain negative impact.

In addition, dump files may be large. Generally, you can use the zip command to compress files to reduce bandwidth overhead during file download. After the dump file is downloaded, you can back up the dump file to a specified location or delete the dump file to release disk space.

• Jstack command

  Printf ‘% x \ n’ tid – > decimal and hexadecimal thread ID (navtive thread) % d decimal jstack pid | grep tid – C 30 — color ps – mp 8278 – o THREAD,tid,time | head -n 40

A Java process has a high CPU usage, and we want to locate the thread with the highest CPU usage.

(1) Use the top command to find out the thread PID that occupies the highest CPU

top -Hp {pid}
Copy the code

(2) The thread ID with the highest usage is 6900, which is converted to hexadecimal (because Java Native threads output in hexadecimal).

printf '%x\n' 6900
Copy the code

(3) Use JStack to print out the Java thread call stack information

jstack 6418 | grep '0x1af4' -A 50 --color
Copy the code

• Jinfo command

  Jinfo-flag ReservedCodeCacheSize 28461 jinfo-flag MaxPermSize 28461

• Jstat command

  jstat -gc pid jstat -gcutil pgrep -u admin java

3

Log analysis

GC Log Analysis

• Detailed analysis of GC logs

Java VIRTUAL machine (JVM) GC logs are important logs used to locate faults. Frequent GC logs decrease application throughput, increase response time, and even cause service unavailability.

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/usr/local/gc/gc.log -XX:+UseConcMarkSweepGC
Copy the code

We can add ** -xx :+PrintGCDetails ** to the Java application’s startup parameter to print the GC log details, but we can also add other auxiliary parameters, such as -xloggc to specify the GC log file address. If this parameter is not enabled for your application, add it to the next restart.

The above picture shows a GC log screenshot of an online application running smoothly.

2017-12-29T18:25:22.753+ 0800:73143.256: [gC2017-12-29T18:25:22.753 + 0800:73143.257: [ParNew: [Times: 3282K -> 3282k] [Times: 3282k -> 3282k] [Times: 3283k] User =0.02 sys=0.00, real=0.02 secs] [2017-12-29T18:25:22.753+ 0800:73143.256] : This GC has occurred since JVM started 73143.256 seconds.[ParNew: 559782 k - > 1000 k (629120 k), 0.0135760 secs] : For the new generation GC, use the ParNew collector, 559782K is the size before the new generation recycling,1000K is the size after the new generation recycling,629120K is the total size of memory allocated by the current new generation, 0.0135760 secS indicates that this new generation recycling takes 0.0135760 seconds [825452K->266673K(2027264K), 0.0140300 secs]:825452K is the size of the reclaimed heap memory,266673K is the size of the memory after the reclaimed heap, [Times: user=0.02 sys=0.00, real=0.02 secs] : The time in user mode is 0.02 seconds; the time in system mode is 0.00. The actual time is 0.02 secondsCopy the code

For both minor and Full GC, we focus on real-time GC collection time, such as real=0.02secs, or Stop the world time. If this time is too long, application performance can be severely affected.

• CMS GC log analysis

Concurrent Mark Sweep (CMS) a Concurrent Mark Sweep (CMS) is an old garbage collector implemented by a mark-and-sweep algorithm. It is divided into six steps:

• STW Initial Mark
• Concurrent marking
• Concurrent Precleaning
• Remarking (STW remark)
• Concurrent cleaning
• Concurrent reset

Among them, STW initial mark and STW remark need to “Stop the World”.

Initial marking: At this stage, The virtual machine is required to Stop The task in progress, officially known as STW (Stop The Word). This process starts with the “root object” of the garbage collection, and only objects that can be directly associated with the “root object” are scanned and marked. So this process suspends the entire JVM, but is quickly completed.

Concurrent markup: This phase follows the initial markup phase, tracing the markup down from the initial markup. In the concurrent marking phase, the application thread and the concurrent marking thread execute concurrently, so the user does not feel the pause.

Concurrent precleanup: The concurrent precleanup phase is still concurrent. In this phase, the virtual machine looks for objects that are new to the old age during the concurrent marking phase (some objects may be promoted from the new generation to the old age, or some objects may be assigned to the old age). By rescanning, reduce The need to “re-mark” in The next phase, because The next phase stops The World.

Relabelling: This phase suspends the virtual machine and the collector thread scans the remaining objects in the CMS heap. Scanning traces back from “with objects” and handles object associations.

Concurrent cleanup: Garbage object cleanup is performed concurrently by the collector thread and the application thread.

Concurrent reset: This phase resets the data structure of the CMS collector and waits for the next garbage collection.

CMS makes it possible to pause application execution only briefly during the entire collection process. This collector can be used by setting -xx :UseConcMarkSweepGC in the JVM parameter, but only for old and Perm (immortal) object collections. CMS reduces the number of times you have to stop the world, which inevitably lengthens the overall GC time.

CMS Initial mark and Remark will both stop the world, which is recorded as two times. The CMS may fail and raise a Full GC again.

The above figure shows a GC log screenshot of an online application in the CMS GC state.

2017-11-02T09:27:03.989+ 0800:558115.552: [GC [1 CMS-initial-mark: 1774783K(1926784K)] 1799438K(2068800K), 0.0123430secs] [Times: User =0.01 sys=0.01, real=0.02 secs] 2017-11-02T09:27:04.001+ 0800:558115.565: [CMS-concurrent-mark-start]2017-11-02T09:27:04.714+ 0800:558116.277: [CMS-concurrent-mark: 0.713/0.713 secs] [Times: User =1.02 sys=0.03, real= 0.71secs] 2017-11-02T09:27:04.714+ 0800:558116.277: [CMS - concurrent - preclean - start] 2017-11-02 T09:27:04. 722 + 0800:558116.285: [CMS - concurrent - preclean: [Times: user= 0.03secs, real= 0.03secs] [Times: user= 0.03secs, real= 0.03secs] 2017-11-02T09:27:04.722+ 0800:558116.286: [CMS - concurrent - abortable - preclean - start] 2017-11-02 T09:27:04. 836 + 0800:558116.399: [GC2017-11-02 T09:27:04. 836 + 0800: [ParNew: 138301K->6543K(142016K), 0.0155540 secs] 1913085K->1781327K(2068800K), 0.0160610 secs] [Times: User =0.03 sys=0.01, real= 0.02secs] 2017-11-02T09:27:05.005+ 0800:558116.569: [cmS-concurrent-abortable-preclean: Secs] [Times: user=0.46 sys=0.02, real= 0.28secs] 2017-11-02T09:27:05.006+ 0800:558116.589: [GC[YG occupancy: 72266 K (142016 K)]2017-11-02T09:27:05.006+ 0800:558116.570: [Rescan (Parallel), 0.2523940 SECS]2017-11-02T09:27:05.259+ 0800:558116.822: [Weak Refs processing, 0.0011240 secs]2017-11-02T09:27:05.260+ 0800:558116.823: [Scrub String table, 0.0028570 secs] [1 CMS-remark: 1774783K(1926784K)] 1847049K(2068800K), 0.2566410 secs] [Times: User =0.14 sys=0.00, real= 0.26secs] 2017-11-02T09:27:05.265+ 0800:558116.829: [CMS - concurrent - sweep - start] 2017-11-02 T09:27:05. 422 + 0800:558116.986: [GC2017-11-02 T09:27:05. 423 + 0800:558116.986: [ParNew: 120207K->2740K(142016K), 0.0179330 secs] 1885446K->1767979K(2068800K), 0.0183340 secs] [Times: User =0.03 sys=0.01, real= 0.02secS] 2017-11-02:27:06.240 + 0800:558117.804: [GC2017-11-02T9:27:06.240 +0800: 558117.804: [ParNew: 116404K->3657K(142016K), 0.0134680secs] 1286444K->1173697K(2068800K), 0.0138460 secs] [Times: [gC2017-11-02T09:27:06.966 +0800: [GC2017-11-02T09:27:06.966+0800: [GC2017-11-02T09:27:06.966+0800: [ParNew: 117321K->2242K(142016K), secs] 738838K->623759K(2068800K), secs] [Times: User =0.03 sys=0.00, real= 0.02secs] 2017-11-02T09:27:07.144+ 0800:558118.708: [CMs-concurrent-sweep: 1.820/1.879 secs] [Times: user= 1.88 sys=0.14, real= 1.888secs] 2017-11-02T09:27:07.144+ 0800:558118.708: [CMs-concurrent-reset: 0.005/0.005 secs] [Times: 2017-11-02T09:27:07.149+ 0800:558118.713: [CMs-concurrent-reset: 0.005/0.005 secs] [Times: 2017-11-02T09:27:07.149+ 0800:558118.713: [CMs-concurrent-reset: 0.005/0.005 secs] User sys = = 0.01 0.00, real = 0.00 secs]Copy the code

If you are familiar with the CMS garbage collection process, you should be able to read the above GC logs easily. I won’t go into detail here.

In addition, CMS garbage collection may also fail.

The exceptions are:

With promMotion failed, then Full GC:

[prommotion failed: The live area ran out of memory, the object entered the old age, and the old age still has no memory to hold the object, which will cause a Full GC]

Concurrent mode failed, then Full GC:

[Concurrent mode failed: CMS collection speed is slow, old age is occupied before CMS is completed, causing a Full GC]

Frequent CMS GC:

[Memory is tight and the old age is full for a long time]

Business log

In addition to system and service exceptions, service logs also pay attention to the service execution time. If a service invocation that takes a long time does not have a circuit breaker, application performance deteriorates or the service becomes unavailable. Service unavailability may lead to avalanches.

The above shows the invocation of an interface. Although most of the invocation does not occur, the execution takes a long time.

Grep ‘[0-9]{3,}ms’ *.log to find dao methods that take more than 3 digits to call

At present, Internet applications almost use distributed architecture, but not limited to service framework, message middleware, distributed cache, distributed storage and so on. So how can these application logs be aggregated for analysis? First, you need a distributed link call tracking system to aggregate all logs by passing through traceId and rpcId between system threads, such as Taobao eagle Eye, Spring Cloud Zipkin, etc

Online fault locating relies on monitoring and logs. Once beyond the scope of monitoring, it is very important to troubleshoot the problem according to the process of thinking, so that we can locate the problem calmly, calmly, and quickly locate the problem on the line.

Online problem location mind map

One Server Layer

1.1 disk

1.1.1 Symptom

When the disk capacity is insufficient, the application often throws the following exception message:

Java.io.IOException: The disk space is insufficientCopy the code

Or an alarm similar to the following:

1.1.2 Troubleshooting Procedure

1.1.2.1 Querying Disk Status using DF

Get the disk state with the following command:

df -h
Copy the code

The result is:

Path/has the maximum usage.

1.1.2.2 Viewing the Folder Size using DU

Get the size of the folder under the directory with the following command:

du -sh *
Copy the code

The result is:

The root folder occupies the largest space, and then find the largest one or several folders.

1.1.2.3 Using LS to View File Sizes

Get the size of the folder under the directory with the following command:

ls -lh
Copy the code

The result is:

You can find that the largest file is the log file and then use the RM command to remove it to free the disk.

1.1.3 Related Commands

1.1.3.1 df

It is used to display file system disk usage statistics on Linux.

(1) Common parameters

Startup parameters:

(2) Result parameters

1.1.3.2 du

The main purpose is to show the size of a directory or file.

(1) Common parameters

Startup parameters:

(2) Result parameters

1.1.3.3 ls

It is mainly used to display information about the contents of the specified working directory.

(1) Common parameters

Startup parameters:

(2) Result parameters

1.2 high CPU

1.2.1 Symptom

When the CPU is too high, the interface performance deteriorates rapidly and the monitoring system starts to alarm.

1.2.2 Troubleshooting Procedure

1.2.2.1 Using Top to Query the Processes with the Highest CPU Usage

Get system CPU usage information with the following command:

top 
Copy the code

The result is:

Thus, the process with a PID of 14201 uses the highest CPU.

1.2.3 Related Commands

1.2.3.1 top

(1) Common parameters

Startup parameters:

Top in-process instruction parameters:

(2) Result parameters

Two application level

2.1 Tomcat suspended animation case analysis

2.1.1 Discovering Faults

Monitoring platform has found a Tomcat node cannot be collected data, even on the server to check the server process is still there, netstat anop | grep port 8001 also have listening, view log print now and then.

2.2.2 Querying Logs

Check NG logs and find that data enters the current server (there are two Tomcats8001 and 8002). NG shows that 8002 node is accessed normally, and there is a 404 error on 8001 node, indicating that Tomcat is in suspended animation and cannot work properly.

If the Tomcat node logs are filtered, exceptions in the OOM are found. However, after the Tomcat node is restarted, the following exceptions are not displayed:

TopicNewController.getTopicSoftList() error="Java heap space From class java.lang.OutOfMemoryError"appstore_apitomcat
Copy the code

2.2.3 Obtaining a Memory Snapshot

If you capture a memory snapshot immediately after an OOM occurs, the user who needs to run the command is the same as the User who needs to start the JAVA process. Otherwise, an exception occurs:

/data/program/jdk/bin/jmap -dump:live,format=b,file=/home/www/jmaplogs/jmap-8001-2.bin 18760 ps -ef|grep XML store. Cn. | grep -v grep | awk '{print $2}' | xargs/data/program/JDK - 1.8.0 comes with _11 / bin/jmap - dump: live, format = b, the file = API. BinCopy the code

The memory dump file is large (1.4GB). Compress the file first and then pull it to the local PC to decompress it using 7ZIP.

Linux compressed dump is.tgz.

Using 7Zip on Windows requires two steps to decompress:

.bin.tgz---.bin.tar--.bin
Copy the code

2.2.4 Analyzing memory Snapshot Files

Using Memory Analyzer to analyze dump files, we found that there are obvious Memory leaks.

Click to view the details, and find that a specific line of the code is located, which is clear at a glance:

Shallow heap and retained heap can be viewed and a large number of objects (810325 objects) are generated. After analysis of the code, it is found that softItem objects are reported more than 3 million objects. During the loop, all data are stored in a method and cannot be released. This causes memory to pile up to 1.5 GIGABytes, exceeding the maximum amount allocated by the JVM, resulting in OOM.

java.lang.Object[810325] @ 0xb0e971e0
Copy the code

2.2.5 Relevant knowledge

2.2.5.1 JVM memory

2.2.5.2 Process of memory allocation

If escape analysis is passed, allocation will be made in TLAB first, and allocation will be made in Eden if conditions are not met.

2.2.4.3 GC

(1) Scenarios triggered by GC

(2) GC Roots

GC Roots have 4 types of objects:

• Objects referred to in the virtual machine stack (the local variable table in the frame) are stored in the heap as Java objects.

• An object referenced by a static property of a class in a method area, usually referred to by a static modifier, is loaded into memory when the class is loaded.

• The object referenced by a constant in the method area.

• Objects referenced by JNI (Native methods) in the native method stack.

(3) GC algorithm

• Serial only uses a single GC thread for processing, while parallel uses multiple.

• In multi-core cases, parallelism is generally more efficient, but in single-core cases, parallelism is not necessarily more efficient than serial.

• The STW suspends the execution of all application threads and waits for the GC thread to complete before resuming the execution of the application thread, resulting in a short period of application unresponsiveness.

• Concurrent causes the GC thread and application thread to execute concurrently, so the application thread and GC thread compete with each other for CPU, resulting in floating garbage and uncontrolled GC time.

(4) GC algorithm used by the new generation

• The new generation algorithms are all based on Coping and are fast.

• Parallel Insane: Throughput is preferred.

• Throughput = time to run user code/(Time to run user code + garbage collection time)

(5) GC algorithm used in the old era

Parallel Compacting

Concurrent Mark-Sweep(CMS)

(6) Garbage collector summary

(7) Combination of algorithms used in actual scenarios

(8) GC log format

(a) Monitor the OOM scenario of memory

Do not manually capture memory snapshots using Jmap online. It is too late to manually capture memory snapshots when the system is OOM. In addition, the generation of dump files consumes system memory resources and causes system crashes. Only need to extract and set the following parameters in JVM startup parameters. Once OOM triggers, corresponding files will be automatically generated and analyzed by MAT.

# memory OOM, automatically generate the dump file - XX: XX: + HeapDumpOnOutOfMemoryError - HeapDumpPath = / data/logs /Copy the code

If the Young GC is frequent and one is printed in 5S or the Old GC is printed, it indicates that the memory setting is too small or there is a memory leak. In this case, the memory snapshot needs to be captured and shared.

(b) Young Gc logs

2020-09-23T01:45:05.487+ 0800:126221.918: [ParNew: 2020-09-23T01:45:05.487+ 0800:126221.918:] 1750755K->2896K(1922432K), secs] 1867906K->120367K(4019584K), secs] [Times: User sys = = 0.13 0.01, real = 0.04 secs]Copy the code

(c) Old GC log

2020-10-27T20:27:57.733+0800: Heap Inspection Initiated GC 2020-10-27T20:27:57.733+0800: 639877.297: [CMS: 165992K->120406K(524288K), 0.7776748 secs] 329034K->120406K(1004928K), [Metaspace: [Times: user= 0.00 sys=0.00, real= 0.00 secs]Copy the code

2.2 The APPLICATION CPU is Too High

2.2.1 Discovering faults

In general, a monitoring alarm is generated:

2.2.2 Finding faulty Processes

Using TOP, the process with the highest CPU usage pid is 14, as shown in the following figure:

2.2.3 Finding the faulty thread

Top-h-p is used to check the threads occupying the highest CPU in the process. It can be seen from the following figure that the problematic threads are mainly activeCpu threads, whose PID is 417.

2.2.4 Querying Details about a thread

• First, use printf “%x \n” to change tid to hexadecimal: xid.

• Reuse jstack | grep nid = 0 x – A 10 query thread information (if process no response, then use jstack -f), information is as follows:

2.2.5 Analyzing code

Java class cpuThread. Java class cpuThread. Java class cpuThread. Java

2.2.6 Conclusion obtained

According to the code and log analysis, it can be seen that the limit value Max is too large, which causes the thread to execute in a loop for a long time, leading to the problem.

Three Mysql

3.1 a deadlock

3.1.1 Problems occur

Recently, as the online traffic increases, the following anomalies suddenly start to be reported, which means the deadlock problem occurs:

Deadlock found when trying to get lock; try restarting transaction ;
Copy the code

3.1.2 Problem analysis

3.1.2.1 Querying the Transaction Isolation Level

Obtain database isolation level information using the select @@tx_isolation command:

3.1.2.2 Querying Database Deadlock Logs

Run the show engine innodb status command to obtain the following deadlock information:

It can be seen from the above that two things try to acquire the X lock (exclusive lock) of the record when they hold S lock (shared lock) on the record at the same time, which leads to deadlock caused by mutual waiting.

3.1.2.3 Code analysis

According to the SQL statement of the deadlock log, the following pseudo-code logic is obtained:

@Transactional(rollbackFor = Exception.class)void saveOrUpdate(MeetingInfo info) { // insert ignore into table values (...). int result = mapper.insertIgnore(info); if (result>0) { return; } // update table set xx=xx where id = xx mapper.update(info); }Copy the code

3.1.2.4 Get conclusions

The analysis obtained the locking sequence that caused the problem as follows, and then modified the code implementation to solve the problem.

3.2 slow SQL

3.1.1 Problems occur

Application TPS drop and SQL execution timeout or an alarm similar to the following usually indicates slow SQL.

3.1.2 Problem analysis

Analyze the execution plan: Use the Explain instruction to obtain the execution plan for this SQL statement, based on which there are two possible scenarios.

• SQL does not follow the index or scans too many rows, resulting in a long execution time.

• SQL is fine, but the execution time is too long due to the waiting lock caused by concurrent transactions.

3.1.3 a scene

3.1.3.1 optimize SQL

Optimize the execution time by adding indexes and adjusting SQL statements, such as the following execution plan:

The type of the execution plan of this SQL is ALL, and according to the following type semantics, we can know that there is no index of the whole table query, so we can add index to its retrieval column to solve the problem.

3.1.4 scenario 2

3.1.4.1 Querying the Current Transaction Status

You can view the following three tables to do the corresponding processing:

Select * from information_schema.innodb_trx; select * from information_schema.innodb_trx; SELECT * FROM information_schema.INNODB_LOCKS; Select * from information_schema.innodb_lock_waits;Copy the code

(1) Check the current transaction:

(2) query transaction lock type index details:

The lock_table field shows the table name of the locked index, the lock_mode field shows the lock type is X, and the lock_type field shows the row lock record.

3.1.4.2 analysis

According to the transaction situation, obtain the table information, and related transaction timing information:

DROP TABLE IF EXISTS `emp`; CREATE TABLE `emp` (`id` int(11) NOT NULL AUTO_INCREMENT,`salary` int(10) DEFAULT NULL,`name` varchar(255) DEFAULT NULL,PRIMARY KEY (`id`),KEY `idx_name` (`name`(191)) USING BTREE) ENGINE=InnoDB AUTO_INCREMENT=6 DEFAULT CHARSET=utf8mb4;Copy the code

A locks A record and does not submit it. B needs to update this record, which will be blocked. The following figure shows the execution sequence:

3.1.4.3 Solution

(1) Modify the scheme

Based on the results of the previous step, the timing sequence of intertransaction locking is analyzed. For example, the blocked transaction SQL can be known through tx_query field, and the transaction state can be known through trx_state, etc., and the corresponding code logic can be found for optimization and modification.

(2) Temporary modification scheme

Trx_mysql_thread_id is the corresponding transaction sessionId. You can run the following command to kill long-running transactions to avoid blocking other transactions.

kill 105853
Copy the code

3.3 Too many Connections

3.3.1 Problems occur

The number of database connections reaches the upper limit.

3.3.2 Solution

Solution:

• Run set global max_connections=XXX to increase the maximum number of connections.

• Use show ProcessList to get connection information, and then kill too many connections.

Common scripts are as follows:

Sort the number of the database connection mysql - h127.0.0.0.1 - uabc_test - pXXXXX P3306 - A - e 'show the processlist | awk' {print $4} '| sort | uniq -c | sort -rn|head -10Copy the code

3.4 Related Knowledge

3.4.1 track index

3.4.1.1 storage Engines of MySql

3.4.1.2 InnoDB B+Tree Index implementation

Primary key index (clustered index) :

• The leaf node data field holds the address of the complete data.

• Primary keys and data are all stored in a tree.

• The Root node resides in the memory.

• One innodb_page_size size per non-leaf node to speed up disk IO.

• Disk I/O is hundreds of times slower than memory, and disk is slow because mechanical devices are slow to find tracks, so disk prefetch is used, reading an integer multiple of one disk page at a time (page: a logical block of computer-managed memory – usually 4k).

• If there is no primary key,MySQL generates an implied field as the primary key by default. This field is 6 bytes long and of type long integer.

• The secondary index structure is the same as the primary index, but the leaf node data field holds the primary key pointer.

• InnoDB is organized in Tablespace Tablespace(idb file) structure, each Tablespace contains multiple segments.

• Each Segment is divided into two types: leaf Segment and non-leaf Segment. A Segment contains multiple extents.

• An Extent occupies 1M space and contains 64 pages (16k for each Page). InnoDB b-tree allocates one physical Page to each logical node and one I/o operation to each node.

• A Page contains a lot of ordered data Row data, which contains information such as Filed attribute data.

InnoDB storage engine page size is 16KB, the typical table primary key type is INT (4 bytes) or BIGINT (8 bytes), pointer type is also generally 4 or 8 bytes, That is, a page (a node in B+Tree) stores approximately 16KB/(8B+8B)=1K keys (K is [10]^3 for easy calculation).

This means that a depth of 3 B+Tree index can maintain 10^3 * 10^3 * 10^3 = 1 billion records.

The left pointer of each index is an index/node smaller than itself, and the right pointer is an index/node greater than or equal to itself.

3.4.2 Retrieving the B+ Tree Index

3.4.2.1 Primary Key Index Retrieval

select * from table where id = 1
Copy the code

3.4.2.2 Auxiliary index retrieval

select * from table where name = 'a'
Copy the code

3.4.3 Isolation level of things

3.4.3.1 How Do I View the Transaction Isolation Level of the Database

To view the isolation level of a transaction, run the following command:

show variables like 'tx_isolation';
Copy the code

The isolation level of RDS on Ali Cloud is read committed, not repeatable read of native mysql.

• Repeatable Read does not have phantom read problem. RR isolation level ensures that the read record is locked (record lock) and the read range is locked. New records that meet the query conditions cannot be inserted (gap lock) and phantom read phenomenon does not exist.

• Among MYSQL’s transaction engines, INNODB is the most widely used. Its default transaction isolation level is REPEATABLE READ(REPEATABLE READ), which does not prevent phantom reads under standard transaction isolation level definitions. INNODB uses next-key locks to prevent phantom locks.

• By default, mysql’s transaction isolation level is repeatable and innodb_lockS_unSAFE_for_binlog parameter is OFF. Next key locks is used by default. Next-key Locks are a combination of Record and gap Locks that lock gaps between indexes in addition to the Record itself. If this parameter can be set to ON, phantom reads occur at the RR isolation level.

3.4.3.2 Multi-version Concurrency Control MVCC

The MySQL InnoDB storage engine is a multi-version Concurrency Control protocol (MVCC). The opposite of MVCC is the Lock-based Concurrency Control.

The biggest benefits of MVCC are familiar: read without locking, read without conflict. In OLTP applications where there are too many reads and too few writes, read and write conflicts are very important, which greatly improves the concurrency performance of the system.

In MVCC concurrency control, read operations can be divided into two categories: Snapshot read and current read.

Snapshot read: a simple select operation. Snapshot read is not locked. (There are exceptions, of course, which will be examined below).

select * from table where ? ;Copy the code

Current read: special read operations, such as insert/update/delete operations, belong to current read and need to be locked.

select * from table where ? The lock in share mode; Select * from table where 'S' (select * from table where 'S' (select * from table where 'S')) for update; Insert into table values (...) ; update table set ? where ? ; delete from table where ? ;Copy the code

3.4.4.3 Scenario Simulation

Statement to modify transaction isolation level:

SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ;  -- READ UNCOMMITTED/READ COMMITTED/REPEATABLE READ/SERIALIZABLE
Copy the code

(1) Dirty reading scene simulation

DROP TABLE IF EXISTS `employee`; CREATE TABLE `employee` ( `id` int(11) NOT NULL, `name` varchar(50) NOT NULL, `salary` int(11) DEFAULT NULL, KEY `IDX_ID` (`id`) USING BTREE) ENGINE=InnoDB DEFAULT CHARSET=utf8; -- ------------------------------ Records of employee-- ----------------------------INSERT INTO `employee` VALUES ('10',  '1s', '10'); INSERT INTO `employee` VALUES ('20', '2s', '20'); INSERT INTO `employee` VALUES ('30', '3s', '30');Copy the code

Dirty read scenario simulation

(2) Unrepeatable read simulation

DROP TABLE IF EXISTS `employee`; CREATE TABLE `employee` ( `id` int(11) NOT NULL, `name` varchar(50) NOT NULL, `salary` int(11) DEFAULT NULL, KEY `IDX_ID` (`id`) USING BTREE) ENGINE=InnoDB DEFAULT CHARSET=utf8; -- ------------------------------ Records of employee-- ----------------------------INSERT INTO `employee` VALUES ('10',  '1s', '10'); INSERT INTO `employee` VALUES ('20', '2s', '20'); INSERT INTO `employee` VALUES ('30', '3s', '30');Copy the code

The point of non-repeatable reads is to modify: the same condition, you read the data, read it again to find a different value.

(3) Phantom reading scene simulation

Table structure and data are as follows: ID is not a primary key or unique index, but a common index. Transaction isolation level is RR, which can simulate the GAP lock scenario.

DROP TABLE IF EXISTS `emp`; CREATE TABLE `emp` ( `id` int(11) NOT NULL, `salary` int(11) DEFAULT NULL, KEY `IDX_ID` (`id`) USING BTREE) ENGINE=InnoDB DEFAULT CHARSET=utf8; -- ------------------------------ Records of emp-- ----------------------------INSERT INTO `emp` VALUES ('10', '10'); INSERT INTO `emp` VALUES ('20', '20'); INSERT INTO `emp` VALUES ('30', '30');Copy the code

If id=20 is changed, multiple locks will be added: X lock will be added to 20, GAP lock will be added to [10-20],[20-30].

Magic reading focuses on adding or deleting (changes in the number of data items). Under the same conditions, the number of records read for the first and second times is different.

REPEATABLE READ does not prevent phantom reading under standard transaction isolation level definitions. INNODB uses two techniques (MVCC AND GAP LOCK) to prevent phantom reading.

3.4.4 Various Innodb locks

3.4.4.1 lock type

• Advantages of table locking: low overhead; Lock. No deadlocks.

• Disadvantages of table locks: Large lock granularity, high probability of lock conflict, and low concurrent processing capability.

• Lock mode: automatic lock. For query operations (SELECT), all tables are automatically locked. For UPDATE operations (UPDATE, DELETE, INSERT), all tables are automatically locked. Locks can also be displayed.

• Shared read lock lock table tableName read

• Exclusive write lock lock table tableName write

• Batch unlocking: Unlock tables

3.4.4.2 row locks

The above lock is only acquired at Repeatable Read and Serializable transaction isolation levels.

3.4.4.3 intent locks

(1) Scene

LOCK TABLE my_TABL_NAME READ; Locking tables with read locks blocks other transactions from modifying table data. LOCK TABLE my_table_name WRITe; Locking the table with a write lock blocks other transaction reads and writes.

Innodb engine also supports row locks. Row locks are shared locks. Exclusive lock, an exclusive read/write lock for a transaction on a row.

Consider this example for the coexistence of these two types of locks:

Transaction A locks A row in the table so that the row can only be read, but not written. Transaction B then requests a write lock for the entire table. If transaction B succeeds, it can theoretically modify any row in the table, which conflicts with the row lock held by A.

The database needs to avoid this conflict, that is, let B’s request block until A releases the row lock.

(2) Problems

How does the database determine this conflict?

(3) The answer

In the case of unintentional locking:

• Step1: Determine whether the table has been locked by another transaction

• Step2: Determine whether each row in the table is locked by a row lock.

In the case of intentional locks:

• Step1: the same

• Step2: The table has an intention to share locks, indicating that some rows in the table are locked by the shared row locks. Therefore, the write lock of the transaction B application form will be blocked.

(4) Summary

In the case of unintentional locking, step2 needs to traverse the entire table to confirm whether the table lock can be obtained. However, in the case of intentional lock, transaction A must apply for intentional shared lock first, and then apply for row lock after it is successful, so it does not need to traverse the whole table again, which improves efficiency. Therefore, intent locking is mainly used to implement multi-grained locking mechanisms (in plain English: for both table and row locking).

3.4.4.4 X/S lock

3.4.4.5 Locking Analysis of an SQL Query

Select * from t1 where id = 10; select * from t1 where id = 10; SQL2: delete from t1 where id = 10;Copy the code

The combination is divided into the following scenarios:

(1) combination of 7 GAP lock detailed reading

Insert operations, such as Insert [10, AA], first locate between [6,c] and [10,b], and then check whether the GAP is locked before insertion. If locked, Insert cannot Insert records. Therefore, through the current read of the first pass, not only the records that meet the condition are locked (x-lock), similar to combination three. At the same time, add 3 GAP locks to lock the 3 gaps that may Insert records meeting the condition, to ensure that the subsequent Insert cannot Insert new records with ID =10, and thus eliminate the illusion of the second current read of the same transaction.

Since GAP locks are needed to prevent illusionary reading, why do combination 5 and combination 6, which are also RR isolation levels, not need GAP locks?

The purpose of the GAP lock is to prevent the illusion of two current reads of the same transaction. And combination five, id is the primary key; Combination 6, id is unique key, can guarantee unique.

An equivalent query can only return one record at most, and a new record of the same value will not be inserted, thus avoiding the use of GAP locks.

(2) Conclusions

• SQL: delete from T1 where ID = 10; SQL: delete from T1 where ID = 10; First, locate the first record that meets the query condition through the ID index, add the X lock on the record, add the GAP lock on the GAP lock, and then add the record X lock on the primary key cluster index, and then return; Then read the next entry and repeat. Until the first record [11,f] does not meet the conditions, at this point, record X lock is not needed, but GAP lock still needs to be added, and finally the end is returned.

• When a GAP lock or nextKey lock is acquired depends on the isolation level. Only specific operations at REPEATABLE READ or above isolation level will acquire a GAP lock or NextKey lock.

3.4.5 Handling Online Problems

3.4.5.1 Observing several common library tables for problems

First, you can check the corresponding system variables and state variables of mysql through two subordinate commands.

Show status like '% ABC %'; show variables like '%abc%';Copy the code

MySQL 5.7.6 MySQL 5.7.6 MySQL 5.7.6 MySQL 5.7.6 MySQL 5.7.6 MySQL 5.7.6

performance_schema.global_variables performance_schema.session_variables performance_schema.variables_by_thread performance_schema.global_status performance_schema.session_status performance_schema.status_by_thread performance_schema.status_by_account performance_schema.status_by_host performance_schema.status_by_user
Copy the code

Previously obtained from the following table:

INFORMATION_SCHEMA.GLOBAL_VARIABLES INFORMATION_SCHEMA.SESSION_VARIABLES INFORMATION_SCHEMA.GLOBAL_STATUS INFORMATION_SCHEMA.SESSION_STATUS
Copy the code

More commonly used system variables and state variables are:

Show variables like 'slow_query_log'; # show variables like 'long_query_time'; # see slow SQL repository paths, general: / home/mysql/data3016 / mysql/slow_query logshow variables like 'slow_query_log_file'; RDS: read-committed Mysql:Repeatable readshow variables like 'TX_ISOLATION '; # innoDB data page size 16384show variables like 'innodb_page_size'; show status like 'innodb_row_%'; SQLSHOW SLOW limit 10; show full slow limit 10; Select @@autocommit; # ibid show variables like 'autocommit'; Set autocommit=1; # show variables like '%storage_engine%'; REPEATABLE READ SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ;Copy the code

3.5 Suggestions

3.5.1 Small tables Drive large tables

• Nb_soft_nature: a small table

• Nb_soft: large tables

• Package_name: both are indexes

The MySQL table association algorithm is Nest Loop Join, which drives the result set of the table as the basic data of the Loop, and then queries the data in the next table one by one through the data in the result set as the filtering condition, and then merges the results.

(1) Small table drive large table

Nb_soft_nature contains only 24 data items. Package_name of each data item is connected to the NB_soft table for query. Because package_name has an index in the NB_soft table, only 24 scans are required.

(2) The big table drives the small table

Again, it takes more than a million scans to return results

3.5.2 Using auto-grow Primary Keys

In combination with the characteristics of B+Tree, the auto-added primary key is continuous, and the page splitting is minimized during the insertion process. Even if the page splitting is required, only a small part of the page splitting will be performed. And it can reduce the movement of data, every insert is inserted to the end. The idea is to reduce the frequency of splitting and movement.

Four Redis

4.1 Troubleshooting Ideas

4.2 Memory Alarms

The following exception message is often displayed:

OOM command not allowed when used memory
Copy the code

4.2.1 Setting an Appropriate Memory size

Set maxMemory and the corresponding reclamation strategy algorithm, preferably set to 3/4 of physical memory, or a smaller proportion, because Redis also need caching when copying data and other services. In case the cache data is too large to cause redis crash, resulting in system error unusable.

(1) Specify in the redis. Conf configuration file

maxmemory xxxxxx
Copy the code

(2) Run commands to change the password

config set  maxmemory xxxxx
Copy the code

4.2.2 Setting an Appropriate memory elimination policy

(1) Specify in the redis. Conf configuration file

maxmemory-policy allkeys-lru
Copy the code

4.2.3 Viewing large Keys

(1) With tools:

Install the tool dbatools redisTools to list the top N keys

/data/program/dbatools-master/redisTools/redis-cli-new -h <ip> -p <port> --bigkeys --bigkey-numb 3
Copy the code

The results are as follows:

Sampled 122114 keys in the keyspace! Total key Length in bytes is 3923725 (AVG Len 32.13) Biggest string key Top 1 found 'xx1' has 36316 bytesBiggest string Key Top 2 found 'xx2' has 1191 bytesBiggest string Key Top 3 found 'xx3' has 234 bytesBiggest list Key Top 1 found 'x4' has 204480 itemsBiggest list Key Top 2 found 'x5' has 119999 itemsBiggest list Key Top 3 found 'x6' has 60000 itemsBiggest set Key Top 1 found 'x7' has 14205 membersBiggest set Key Top 2 found 'x8' has 292 membersBiggest set Key Top 3 found 'x,7' has 21 membersBiggest hash Key Top 1 found 'x' has 302939 fieldsBiggest hash Key Top 2 found 'xc' has 92029 fieldsBiggest hash Key Top 3 found 'xd' has 39634 fieldsCopy the code

Native commands are:

/usr/local/redis-3.0.5/src/redis-cli -c -h < IP > -p <port> --bigkeysCopy the code

Analyze all keys/certain types of usage in RDB files:

rdb -c memory dump.rdb -t list -f dump-formal-list.csv
Copy the code

Check the memory usage of a key:

[root@iZbp16umm14vm5kssepfdpZ redisTools]# redis-memory-for-key -s < IP > -p <port> xKey xBytes 4274388.0Type hashEncoding  hashtableNumber of Elements 39634Length of Largest Element 29Copy the code

(2) In the absence of tools, the following instructions can be used to evaluate the key size:

debug object key
Copy the code

4.3 Redis slow command

4.3.1 Setting the Redis Slow command Time threshold (unit: subtle)

(1) Use the redis. Conf configuration file

Record the number of microseconds (microsecond, 1 second = 1,000,000 microseconds) in which the query is executed. Slowlog-log-lower-than 1000 # Maximum number of logs slowlog-max-len 200Copy the code

(2) Through command

Slowlog-log-lower-than 1000: saves 200 slowlog-max-len records: config-set slowlog-max-len 200Copy the code

4.3.2 Viewing the Slow Command of Redis

slowlog get
Copy the code

4.4 Too many Connections

(1) Specify the maximum number of connections in the redis.conf configuration file

maxclients 10000
Copy the code

(2) Run commands to change the password

config set maxclients xxx
Copy the code

4.5 Processing flow after one Online Redis node fails

4.5.1 Viewing node Status

A dead node is displayed after the cluster Nodes command is executed:

[rgp@iZ23rjcqbczZ ~]$/data/program/redis-3.0.3/bin/redis-cli -c h < IP > -p <port> IP :port> cluster nodes9f194f671cee4a76ce3b7ff14d3bda190e0695d5 m1 master - 0 1550322872543 65 connected 10923-16383a38c6f957f2706f269cf5d9b628586a9372265e9 s1 slave 9f194f671cee4a76ce3b7ff14d3bda190e0695d5 0 1550322872943 65  connected77ce43ec23f25f77ec68fe71ae3cb799e7300c6d s2 slave 03d72a3a5050c85e280e0bbeb687056b84f10077 0 1550322873543 63 connected03d72a3a5050c85e280e0bbeb687056b84f10077 m2 master - 0 1550322873343 63 connected 5461-109225799070c6a63314296f3661b315b95c6328779f7 :0 slave,fail,noaddr 6147bf416ef216b6a1ef2f100d15de4f439b7352 1550320811474 1550320808793 49 disconnected6147bf416ef216b6a1ef2f100d15de4f439b7352 m3 myself,master - 0 0 49 connected 0-5460.Copy the code

4.5.2 Removing an Incorrect Node

(1) Cluster forget is required for each node after the following deletion operations fail to be performed:

IP: port > cluster forget 61 c70a61ad91bbac231e33352f5bdb9eb0be6289cluster forget < node_id > removed from the cluster node_id specified nodeCopy the code

(2) Delete the failed node:

[rgp@iZ23rjcqbczZ ~]$ /data/program/redis-3.0.3/bin/redis-trib.rb del-node m3 b643d7baa69922b3fdbd1e25ccbe6ed73587b948>>> Removing node b643d7baa69922b3fdbd1e25ccbe6ed73587b948 from cluster m3>>> Sending CLUSTER FORGET messages to the cluster...>>> SHUTDOWN the node.
Copy the code

(3) Clear the RDB aof nodes.conf file in the node configuration directory. Otherwise, the following exceptions may occur when the node is started:

[ERR] Node s3 is not empty. Either the node already knows other nodes (check with CLUSTER NODES) or contains some key in  database 0.Copy the code

4.5.3 Restoring a Node

(1) Start a node of Redis in the background:

/ data/program/redis - 3.0.3 / bin/redis server/data/program/redis - 3.0.3 / etc / 7001 / redis. ConfCopy the code

(2) Add the node to the cluster:

[root@iZ23rjcqbczZ RGP]# /data/program/redis-3.0.3/bin/redis-trib.rb add-node --slave --master-id 6147bf416ef216b6a1ef2f100d15de4f439b7352 s3 m3>>> Adding node s3 to cluster m3>>> Performing Cluster Check (using node m3)M: 6147bf416ef216b6a1ef2f100d15de4f439b7352 m3 slots:0-5460 (5461 slots) master 0 additional replica(s)M: 9f194f671cee4a76ce3b7ff14d3bda190e0695d5 m1 slots:10923-16383 (5461 slots) master 1 additional replica(s)S: a38c6f957f2706f269cf5d9b628586a9372265e9 s1 slots: (0 slots) slave replicates 9f194f671cee4a76ce3b7ff14d3bda190e0695d5S: 77ce43ec23f25f77ec68fe71ae3cb799e7300c6d s2 slots: (0 slots) slave replicates 03d72a3a5050c85e280e0bbeb687056b84f10077M: 03d72a3a5050c85e280e0bbeb687056b84f10077 m2 slots:5461-10922 (5462 slots) master 1 additional replica(s)[OK] All nodes agree about slots configuration.>>> Check for open slots... >>> Check slots coverage... [OK] All 16384 slots covered.>>> Send CLUSTER MEET to node s3 to make it join the cluster.Waiting for the cluster to join.. >>> Configure node as replica of m3.[OK] New node added correctly.Copy the code

• S3: IP address of the secondary node to be added: port

• M3: IP address of the primary node: port

• 6147 bf416ef216b6a1ef2f100d15de4f439b7352: the master node number

Five network

5.1 Troubleshooting Process

5.1.1 Symptoms occur

In non-pressure or peak conditions, a large number of 503 error codes suddenly appear, and the page cannot be opened.

5.1.2 Checking whether a DOS attack occurs

If a large number of semi-connected states exist on the Server and the source IP addresses are random, SYN attacks are detected. Run the following command to disable SYN attacks.

netstat -n|grep SYN_RECV
Copy the code

5.1.3 Checking TCP Connection Status

Check whether the total number of TCP connections is normal by using the following methods:

Netstat anoe | 8000 | grep wc -l to see 8000Copy the code

Then use the following command to check whether the number of connections in each state is normal:

netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
Copy the code

Based on the above information, if the number of TIME_WAIT states is too large, you can run the following command to view the IP addresses with the most CLOSE_WAIT connections and analyze the problem with the service:

netstat -n|grep TIME_WAIT|awk '{print $5}'|awk -F: '{print $1}'|sort|uniq -c|sort -nr|head -10
Copy the code

5.2 Related Knowledge

5.2.1 TCP connection

TCP three handshakes four waves

Why does the client need to confirm again in Step 3? This is mainly to prevent the invalid connection request packet segment suddenly returned to the server to generate an error scenario:

The so-called “invalid connection request segment” is generated in this way. Normally, the client sends a connection request but does not receive an acknowledgement because the connection request packet is lost. The client makes a second connection request, receives confirmation, and establishes the connection. After data transmission is complete, the connection is released. The client sends two connection request segments. The first one is lost and the second one reaches the server without “invalid connection request segment”.

Now suppose that the segment of the first connection request message sent by the client is not lost, but is stuck at some network node for so long that it does not reach the server until some point after the connection is released. The connection request is invalid, but when the server receives the invalid connection request, it mistakenly thinks that the client has sent a new connection request. Then the server sends a request message segment to the client, agreeing to establish a connection. Assuming no three-way handshake, the connection is established as soon as the server issues an acknowledgement.

Since the client does not request the connection to be established, it does not respond to the confirmation of the server and does not send data to the server. However, the server assumes that the new transport connection has been established and waits for the data to be sent from the client, thus wasting a lot of resources on the server.

The three-way handshake prevents this from happening. For example, in the above scenario, the client does not send an acknowledgement request to the server, and since the server does not receive the acknowledgement, it knows that the client has not requested a connection.

SYN attacks are typical DDOS attacks. The SYN attack detection method is very simple. If a large number of half-connected states exist on the Server and the source IP addresses are random, the Server is under SYN attack.

netstat -nap | grep SYN_RECV
Copy the code

5.2.2 Some Common Questions

(1) Why the establishment of a TCP connection requires only three handshakes and the release of a TCP connection requires four handshakes?

After receiving a SYN packet in LISTEN state, the server sends the ACK and SYN packets to the client. When the connection is closed, when I received the other side of the FIN message just said there was no need to send the data of the each other, but also can receive data, their own do not necessarily all data has been sent to each other, so their can immediately shut down, also can all data should be sent by send FIN again after sent a message to the client to agree now close the connection.

From this point of view, the ACK and FIN of the server are usually sent separately.

(2) What if the connection has been established, but the client suddenly fails?

TCP also has a keepalive timer, so obviously if the client fails, the server can’t wait forever and waste resources. The server resets this timer every time it receives a request from the client, usually for two hours. If it does not receive any data from the client within two hours, the server sends a probe segment, which is then sent every 75 seconds. If there is no response after 10 probe packets are sent, the server assumes that the client is faulty and closes the connection.

(3) Why does the state of TIME_WAIT take 2MSL to return to the CLOSE state?

Although logically, all four packets are sent and we can directly enter the CLOSE state, we must pretend that the network is unreliable and the last ACK can be lost. Therefore, the TIME_WAIT state is used to resend ACK packets that may be lost.

The Client sends the last ACK reply, but the ACK may be lost. If the Server does not receive an ACK, it repeatedly sends FIN fragments. Therefore, the Client cannot shut down immediately. It must confirm that the Server received the ACK. The Client enters the TIME_WAIT state after sending an ACK. The Client sets a timer and waits for 2MSL of time. If a FIN is received again within that time, the Client resends the ACK and waits for another 2MSL. The so-called 2MSL is twice the MSL(Maximum Segment Lifetime).

MSL refers to the maximum lifetime of a fragment in the network. 2MSL refers to the maximum time required for a send and a reply. If the Client does not receive a FIN again until 2MSL, the Client concludes that the ACK has been successfully received and terminates the TCP connection.

Service exception logs

6.1 Problems Occur

Active alarm is generated by service log monitoring or passive discovery by viewing error logs:

6.2 Log Analysis

6.2.1 Confirming the Log format

The log format is as follows:

<property name="METRICS_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS}|${APP_NAME}|%X{className}|%X{methodName}|%X{responseStatus}|%X{timeConsume}|%X{traceId}|%X{errorCode}|%msg %n"/> <property name="ERROR_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS}|%-5level|%X{traceId}|${APP_NAME}|%serverIp|%X{tenantId}|%X{accountId}|%thread|%logger{30}|%msg%n"/> <! - log format time level of | | | | link id application name server IP name threads | | | | the tenant id user id logger name | business messages - > < property name = "BIZ_LOG_PATTERN" value = "% d {yyyy - MM - dd HH:mm:ss.SSS}|%-5level|%X{traceId}|${APP_NAME}|%serverIp|%X{tenantId}|%X{accountId}|%thread|%logger{30}|%msg%n"/>Copy the code

6.2.2 Retrieving exceptions in log Files

To obtain details about the exception, run the following command:

cat error.log|grep -n " java.lang.reflect.InvocationTargetException"
Copy the code

Based on the log format and log information, the traceId is 489D71FE-67DB-4F59-A916-33F25D35CAB8. Then run the following command to obtain the log information about the entire process:

cat biz.log |grep -n '489d71fe-67db-4f59-a916-33f25d35cab8'
Copy the code

6.2.3 Code analysis

Then according to the above process log to find the corresponding code implementation, and then specific business analysis.