Fejlfinding af softwareimplementering med strace

Fejlfinding af softwareimplementering med strace

Mit daglige job er for det meste softwareimplementering, hvilket betyder, at jeg bruger meget tid på at forsøge at besvare spørgsmål som:

  • Denne software virker for udvikleren, men ikke for mig. Hvorfor?
  • I går virkede denne software for mig, men i dag gør den det ikke. Hvorfor?

Dette er en slags debugging, der er lidt anderledes end almindelig software-debugging. Regelmæssig debugging handler om kodens logik, men implementeringsfejlretning handler om interaktionen mellem koden og miljøet. Selvom roden til problemet er en logisk fejl, betyder det, at alt fungerer på én maskine og ikke på en anden, at problemet på en eller anden måde er i miljøet.

Så i stedet for de sædvanlige fejlfindingsværktøjer som gdb Jeg har et andet sæt værktøjer til debugging implementering. Og mit yndlingsværktøj til at håndtere problemet som "Hvorfor virker denne software ikke for mig?" hedder strace.

Hvad er strace?

strace er et værktøj til "systemopkaldssporing". Det blev oprindeligt skabt til Linux, men de samme fejlfindingstricks kan udføres med værktøjer til andre systemer (DTrace eller ktrace).

Den grundlæggende applikation er meget enkel. Du skal bare køre strace med en hvilken som helst kommando, og den vil dumpe alle systemkald (selvom først du sandsynligvis skal installere det selv strace):

$ strace echo Hello
...Snip lots of stuff...
write(1, "Hellon", 6)                  = 6
close(1)                                = 0
close(2)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

Hvad er disse systemopkald? Dette er noget som en API til operativsystemkernen. Engang havde software direkte adgang til den hardware, den kørte på. Hvis den for eksempel skulle vise noget på skærmen, spillede den med porte eller hukommelseskortede registre til videoenheder. Da multitasking-computersystemer blev populære, herskede kaos, da forskellige applikationer kæmpede om hardwaren. Fejl i én applikation kan ødelægge andre, hvis ikke hele systemet. Derefter dukkede privilegietilstande (eller "ringbeskyttelse") op i CPU'en. Kernen blev den mest privilegerede: den fik fuld adgang til hardwaren, hvilket skabte mindre privilegerede applikationer, der allerede skulle anmode om adgang fra kernen for at interagere med hardwaren gennem systemkald.

På det binære niveau er et systemkald lidt anderledes end et simpelt funktionskald, men de fleste programmer bruger en wrapper i standardbiblioteket. De der. POSIX C standardbiblioteket indeholder et funktionskald skrive(), som indeholder al den arkitekturspecifikke kode for systemkaldet skriver.

Fejlfinding af softwareimplementering med strace

Kort sagt, enhver interaktion mellem en applikation og dens miljø (computersystemer) udføres gennem systemkald. Derfor, når software fungerer på én maskine, men ikke på en anden, ville det være godt at se på resultaterne af systemopkaldssporingen. Mere specifikt er her en liste over typiske punkter, der kan analyseres ved hjælp af en systemopkaldssporing:

  • Konsol I/O
  • Netværk I/O
  • Filsystemadgang og fil I/O
  • Håndtering af levetiden for en procestråd
  • Hukommelsesstyring på lavt niveau
  • Adgang til specifikke enhedsdrivere

Hvornår skal man bruge strace?

I teorien, strace bruges med ethvert program i brugerrummet, fordi ethvert program i brugerrummet skal foretage systemkald. Det fungerer mere effektivt med kompilerede programmer på lavt niveau, men det fungerer også med sprog på højt niveau som Python, hvis du kan skære igennem den ekstra støj fra runtime og tolk.

I al sin pragt strace viser sig under fejlfinding af software, der fungerer godt på én maskine, men pludselig holder op med at arbejde på en anden, producerer vage beskeder om filer, tilladelser eller mislykkede forsøg på at udføre nogle kommandoer eller noget andet... Det er ærgerligt, men det gør det ikke kombineres så godt med problemer på højt niveau, såsom certifikatbekræftelsesfejl. Normalt kræver dette en kombination straceSommetider spor og værktøjer på højere niveau (som kommandolinjeværktøjet openssl for at fejlsøge certifikatet).

Vi vil bruge en selvstændig server som eksempel, men systemopkaldssporing kan ofte udføres på mere komplekse implementeringsplatforme. Du skal bare vælge de rigtige værktøjer.

Simpelt debugging eksempel

Lad os sige, at du vil køre den fantastiske serverapplikation foo, og det er det, du ender med:

$ foo
Error opening configuration file: No such file or directory

Den kunne tilsyneladende ikke finde den konfigurationsfil, du skrev. Dette sker, fordi nogle gange, når pakkeadministratorer kompilerer et program, tilsidesætter de de forventede filplaceringer. Og hvis du følger installationsvejledningen for en distribution, finder du i en anden filer, der er helt anderledes, end du havde forventet. Problemet kunne løses på et par sekunder, hvis fejlmeddelelsen fortalte, hvor man skulle lede efter konfigurationsfilen, men det gør den ikke. Så hvor skal man lede?

Hvis du har adgang til kildekoden, kan du læse den og finde ud af alt. En god backup-plan, men ikke den hurtigste løsning. Du kan ty til en trin-for-trin debugger som gdb og se, hvad programmet gør, men det er meget mere effektivt at bruge et værktøj, der er specielt designet til at vise interaktion med miljøet: strace.

Output strace kan virke overflødig, men den gode nyhed er, at det meste af det sikkert kan ignoreres. Det er ofte nyttigt at bruge operatoren -o til at gemme sporingsresultater i en separat fil:

$ strace -o /tmp/trace foo
Error opening configuration file: No such file or directory
$ cat /tmp/trace
execve("foo", ["foo"], 0x7ffce98dc010 /* 16 vars */) = 0
brk(NULL)                               = 0x56363b3fb000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=25186, ...}) = 0
mmap(NULL, 25186, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f2f12cf1000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "177ELF2113 3 > 1 260A2 "..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1824496, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f2f12cef000
mmap(NULL, 1837056, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f2f12b2e000
mprotect(0x7f2f12b50000, 1658880, PROT_NONE) = 0
mmap(0x7f2f12b50000, 1343488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7f2f12b50000
mmap(0x7f2f12c98000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16a000) = 0x7f2f12c98000
mmap(0x7f2f12ce5000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7f2f12ce5000
mmap(0x7f2f12ceb000, 14336, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f2f12ceb000
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7f2f12cf0500) = 0
mprotect(0x7f2f12ce5000, 16384, PROT_READ) = 0
mprotect(0x56363b08b000, 4096, PROT_READ) = 0
mprotect(0x7f2f12d1f000, 4096, PROT_READ) = 0
munmap(0x7f2f12cf1000, 25186)           = 0
openat(AT_FDCWD, "/etc/foo/config.json", O_RDONLY) = -1 ENOENT (No such file or directory)
dup(2)                                  = 3
fcntl(3, F_GETFL)                       = 0x2 (flags O_RDWR)
brk(NULL)                               = 0x56363b3fb000
brk(0x56363b41c000)                     = 0x56363b41c000
fstat(3, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0x8), ...}) = 0
write(3, "Error opening configuration file"..., 60) = 60
close(3)                                = 0
exit_group(1)                           = ?
+++ exited with 1 +++

Cirka hele den første side af output strace - Dette er normalt forberedelse på lavt niveau til lancering. (Mange opkald mmap, mbeskytte, brk til ting som at detektere hukommelse på lavt niveau og vise dynamiske biblioteker.) Faktisk under fejlfinding af outputtet strace Det er bedre at læse helt fra slutningen. Der vil være en udfordring nedenfor skriver, som viser en fejlmeddelelse. Vi kigger ovenover og ser det første fejlagtige systemkald - opkaldet åbnet, hvilket giver en fejl ENOENT ("fil eller mappe ikke fundet") forsøger at åbne /etc/foo/config.json. Det er her konfigurationsfilen skal være.

Dette var kun et eksempel, men jeg vil sige 90% af tiden, som jeg bruger strace, der er ikke noget meget sværere at gøre end dette. Nedenfor er en komplet trin-for-trin fejlretningsvejledning:

  • Bliv ked af det på grund af en vag besked om en system-y-fejl fra et program
  • Genstart programmet med strace
  • Find fejlmeddelelsen i sporingsresultaterne
  • Gå højere, indtil du rammer det første mislykkede systemkald

Det er meget sandsynligt, at systemkaldet i trin 4 vil afsløre, hvad der gik galt.

tips

Før jeg viser dig et eksempel på mere kompleks debugging, vil jeg vise dig et par tricks til effektiv brug strace:

mand er din ven

På mange *nix-systemer kan en komplet liste over systemkald til kernen fås ved at køre mand syscaller. Du vil se ting som brk(2), hvilket betyder, at flere oplysninger kan fås ved at køre mand 2 brk.

Lille rive: mand 2 gaffel viser mig siden til skallen gaffel() в GNU libc, som, det viser sig, implementeres ved at ringe klone(). Kald semantik gaffel forbliver den samme, hvis du skriver et program vha gaffel(), og kør et spor - jeg kan ikke finde nogen opkald gaffel, i stedet for dem vil der være klone(). Sådanne rakes forvirrer dig kun, hvis du begynder at sammenligne kilden med outputtet strace.

Brug -o for at gemme outputtet til en fil

strace kan generere omfattende output, så det er ofte nyttigt at gemme sporingsresultater i separate filer (som i eksemplet ovenfor). Dette hjælper også med at undgå at forveksle programoutput med output strace i konsollen.

Brug -s til at se flere argumentdata

Du har måske bemærket, at anden halvdel af fejlmeddelelsen ikke vises i eksempelsporet ovenfor. Det er fordi strace standard viser kun de første 32 bytes af strengargumentet. Hvis du vil se mere, så tilføj noget som f.eks -s 128 til opkaldet strace.

-y gør det nemmere at spore filer, sockets osv.

"All is file" betyder, at *nix-systemer udfører alle I/O ved hjælp af filbeskrivelser, uanset om det gælder for en fil eller et netværk eller interprocess-pipes. Dette er praktisk til programmering, men gør det svært at holde styr på, hvad der virkelig foregår, når du ser fælles læse и skriver i systemopkaldssporingsresultaterne.

Ved at tilføje en operatør ja, vil du tvinge strace anmærk hver filbeskrivelse i outputtet med en note om, hvad den peger på.

Tilknyt en allerede kørende proces med -p**

Som du vil se fra eksemplet nedenfor, skal du nogle gange spore et program, der allerede kører. Hvis det vides, at det kører som proces 1337 (f.eks. fra output ps), så kan du spore det sådan her:

$ strace -p 1337
...system call trace output...

Du har muligvis brug for root-rettigheder.

Brug -f til at overvåge underordnede processer

strace Som standard sporer den kun én proces. Hvis denne proces afføder underordnede processer, så kan systemkaldet for at skabe underordnet proces ses, men underordnet processens systemkald vil ikke blive vist.

Hvis du mener, at fejlen er i en underordnet proces, skal du bruge erklæringen -f, vil dette aktivere dets sporing. Ulempen ved dette er, at outputtet vil forvirre dig endnu mere. Hvornår strace sporer én proces eller én tråd, den viser en enkelt strøm af opkaldsbegivenheder. Når den sporer flere processer på én gang, kan du se starten på et opkald afbrudt af en besked , derefter - en masse opfordringer til andre henrettelsesgrene, og først derefter - slutningen af ​​den første . Eller opdel alle sporingsresultater i forskellige filer, også ved hjælp af operatoren -ff (detaljer i guidestrace).

Filtrer spor ved hjælp af -e

Som du kan se, er resultatet af sporingen en rigtig bunke af alle mulige systemopkald. Flag -e Du kan filtrere sporet (se lederskabstrace). Den største fordel er, at det er hurtigere at køre en filtreret trace end at lave en fuld trace og derefter grep`kl. For at være ærlig er jeg næsten altid ligeglad.

Ikke alle fejl er dårlige

Et simpelt og almindeligt eksempel er et program, der leder efter en fil flere steder på én gang, som en shell, der leder efter en mappe, der indeholder en eksekverbar fil:

$ strace sh -c uname
...
stat("/home/user/bin/uname", 0x7ffceb817820) = -1 ENOENT (No such file or directory)
stat("/usr/local/bin/uname", 0x7ffceb817820) = -1 ENOENT (No such file or directory)
stat("/usr/bin/uname", {st_mode=S_IFREG|0755, st_size=39584, ...}) = 0
...

Heuristik som "sidste mislykkede anmodning før rapportering af en fejl" er gode til at finde relevante fejl. Hvorom alting er, så er det logisk at starte helt fra slutningen.

C-programmeringsvejledninger kan hjælpe dig med at forstå systemopkald.

Standardkald til C-biblioteker er ikke systemkald, men kun et tyndt overfladelag. Så hvis du i det mindste forstår lidt hvordan og hvad du skal gøre i C, vil det være lettere for dig at forstå resultaterne af systemopkaldssporingen. For eksempel har du problemer med at fejlfinde opkald til netværkssystemer, se på den samme klassiker Bijas guide til netværksprogrammering.

Et mere komplekst fejlfindingseksempel

Jeg har allerede sagt, at eksemplet med simpel debugging er et eksempel på, hvad jeg mest skal forholde mig til, når jeg arbejder med strace. Nogle gange kræves der dog en reel undersøgelse, så her er et virkeligt eksempel på mere avanceret fejlfinding.

bcron - Opgavebehandlingsplanlægger, en anden implementering af *nix-dæmonen cron. Det er installeret på serveren, men når nogen forsøger at redigere tidsplanen, sker dette:

# crontab -e -u logs
bcrontab: Fatal: Could not create temporary file

Okay, det betyder bcron forsøgte at skrive en bestemt fil, men det lykkedes ikke, og han vil ikke indrømme hvorfor. Afdækning strace:

# strace -o /tmp/trace crontab -e -u logs
bcrontab: Fatal: Could not create temporary file
# cat /tmp/trace
...
openat(AT_FDCWD, "bcrontab.14779.1573691864.847933", O_RDONLY) = 3
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f82049b4000
read(3, "#Ansible: logsaggn20 14 * * * lo"..., 8192) = 150
read(3, "", 8192)                       = 0
munmap(0x7f82049b4000, 8192)            = 0
close(3)                                = 0
socket(AF_UNIX, SOCK_STREAM, 0)         = 3
connect(3, {sa_family=AF_UNIX, sun_path="/var/run/bcron-spool"}, 110) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f82049b4000
write(3, "156:Slogs #Ansible: logsaggn20 1"..., 161) = 161
read(3, "32:ZCould not create temporary f"..., 8192) = 36
munmap(0x7f82049b4000, 8192)            = 0
close(3)                                = 0
write(2, "bcrontab: Fatal: Could not creat"..., 49) = 49
unlink("bcrontab.14779.1573691864.847933") = 0
exit_group(111)                         = ?
+++ exited with 111 +++

Der er en fejlmeddelelse helt til sidst skriver, men denne gang er noget anderledes. For det første er der ingen relevant systemopkaldsfejl, som normalt opstår før dette. For det andet er det klart, at nogen allerede har læst fejlmeddelelsen et sted. Det ser ud til, at det virkelige problem er et andet sted, og bcrontab afspiller blot beskeden.

Hvis du ser på mand 2 læst, kan du se, at det første argument (3) er en filbeskrivelse, som *nix bruger til al I/O-behandling. Hvordan finder jeg ud af, hvad filbeskrivelse 3 repræsenterer? I dette særlige tilfælde kan du løbe strace med operatør ja (se ovenfor), og det vil automatisk fortælle dig det, men for at finde ud af ting som dette, er det nyttigt at vide, hvordan man læser og analyserer sporingsresultater.

Kilden til en filbeskrivelse kan være et af mange systemkald (det hele afhænger af, hvad deskriptoren er til - en konsol, en netværkssocket, selve filen eller noget andet), men uanset hvad, så leder vi efter opkald ved at returnere 3 (dvs. vi ser efter "= 3" i sporingsresultaterne). I dette resultat er der 2 af dem: åbnet helt i toppen og sokkel I midten. åbnet åbner filen men tæt(3) vil så vise, at den lukker igen. (Rake: filbeskrivelser kan genbruges, når de åbnes og lukkes). Opkald stikkontakt () velegnet, fordi det er den sidste før Læs(), og det viser sig, at bcrontab arbejder med noget gennem en socket. Den næste linje viser, at filbeskrivelsen er knyttet til unix domæne socket på vej /var/run/bcron-spool.

Så vi er nødt til at finde processen forbundet med unix fatning på den anden side. Der er et par smarte tricks til dette formål, som begge er nyttige til fejlretning af serverinstallationer. Den første er at bruge netstat eller nyere ss (stikkontaktstatus). Begge kommandoer viser systemets aktive netværksforbindelser og tager erklæringen -l at beskrive lyttestik, samt operatøren -p at vise programmer tilsluttet stikket som en klient. (Der er mange flere nyttige muligheder, men disse to er tilstrækkelige til denne opgave.)

# ss -pl | grep /var/run/bcron-spool
u_str LISTEN 0   128   /var/run/bcron-spool 1466637   * 0   users:(("unixserver",pid=20629,fd=3))

Dette tyder på, at lytteren er kommandoen inixserver, der kører med proces-id 20629. (Og tilfældigvis bruger den filbeskrivelse 3 som socket.)

Det andet virkelig nyttige værktøj til at finde den samme information kaldes lsof. Den viser alle åbne filer (eller filbeskrivelser) på systemet. Eller du kan få oplysninger om en bestemt fil:

# lsof /var/run/bcron-spool
COMMAND   PID   USER  FD  TYPE  DEVICE              SIZE/OFF  NODE    NAME
unixserve 20629 cron  3u  unix  0x000000005ac4bd83  0t0       1466637 /var/run/bcron-spool type=STREAM

Process 20629 er en langvarig server, så du kan tilslutte den til strace bruge noget som strace -o /tmp/trace -p 20629. Hvis du redigerer et cron-job i en anden terminal, vil du modtage et sporingsoutput med en fejl. Og her er resultatet:

accept(3, NULL, NULL)                   = 4
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7faa47c44810) = 21181
close(4)                                = 0
accept(3, NULL, NULL)                   = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=21181, si_uid=998, si_status=0, si_utime=0, si_stime=0} ---
wait4(0, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG|WSTOPPED, NULL) = 21181
wait4(0, 0x7ffe6bc36764, WNOHANG|WSTOPPED, NULL) = -1 ECHILD (No child processes)
rt_sigaction(SIGCHLD, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, 8) = 0
rt_sigreturn({mask=[]})                 = 43
accept(3, NULL, NULL)                   = 4
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7faa47c44810) = 21200
close(4)                                = 0
accept(3, NULL, NULL)                   = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=21200, si_uid=998, si_status=111, si_utime=0, si_stime=0} ---
wait4(0, [{WIFEXITED(s) && WEXITSTATUS(s) == 111}], WNOHANG|WSTOPPED, NULL) = 21200
wait4(0, 0x7ffe6bc36764, WNOHANG|WSTOPPED, NULL) = -1 ECHILD (No child processes)
rt_sigaction(SIGCHLD, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, {sa_handler=0x55d244bdb690, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7faa47ab9840}, 8) = 0
rt_sigreturn({mask=[]})                 = 43
accept(3, NULL, NULL

(Sidst acceptere () vil ikke blive afsluttet ved sporing.) Igen, desværre, indeholder dette resultat ikke den fejl, vi leder efter. Vi kan ikke se nogen beskeder, som bcrontag sender til eller modtager fra socket. Fuldstændig proceskontrol (klone, vent 4, SIGCHLD osv.) Denne proces afføder en underordnet proces, som, som du måske kan gætte, udfører det virkelige arbejde. Og hvis du har brug for at fange hendes spor, så føj til opkaldet strace -f. Dette er, hvad vi finder, når vi søger efter fejlmeddelelsen i det nye resultat med strace -f -o /tmp/trace -p 20629:

21470 openat(AT_FDCWD, "tmp/spool.21470.1573692319.854640", O_RDWR|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied) 
21470 write(1, "32:ZCould not create temporary f"..., 36) = 36
21470 write(2, "bcron-spool[21470]: Fatal: logs:"..., 84) = 84
21470 unlink("tmp/spool.21470.1573692319.854640") = -1 ENOENT (No such file or directory)
21470 exit_group(111)                   = ?
21470 +++ exited with 111 +++

Nå, det er noget. Proces 21470 modtager en "adgang nægtet"-fejl, når den forsøger at oprette en fil på stien tmp/spool.21470.1573692319.854640 (vedrørende den aktuelle arbejdsmappe). Hvis vi bare kendte den aktuelle arbejdsmappe, ville vi også kende den fulde sti og være i stand til at finde ud af, hvorfor processen ikke kan oprette sin midlertidige fil i den. Desværre er processen allerede afsluttet, så du kan ikke bare bruge lsof -p 21470 for at finde den aktuelle mappe, men du kan arbejde i den modsatte retning - se efter PID 21470-systemkald, der ændrer mappen. (Hvis der ikke er nogen, skal PID 21470 have arvet dem fra sin forælder, og dette er allerede gennemført lsof -s kan ikke findes.) Dette systemkald er chdir (hvilket er nemt at finde ud af ved hjælp af moderne online søgemaskiner). Og her er resultatet af omvendte søgninger baseret på sporingsresultaterne, hele vejen til server PID 20629:

20629 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7faa47c44810) = 21470
...
21470 execve("/usr/sbin/bcron-spool", ["bcron-spool"], 0x55d2460807e0 /* 27 vars */) = 0
...
21470 chdir("/var/spool/cron")          = 0
...
21470 openat(AT_FDCWD, "tmp/spool.21470.1573692319.854640", O_RDWR|O_CREAT|O_EXCL, 0600) = -1 EACCES (Permission denied) 
21470 write(1, "32:ZCould not create temporary f"..., 36) = 36
21470 write(2, "bcron-spool[21470]: Fatal: logs:"..., 84) = 84
21470 unlink("tmp/spool.21470.1573692319.854640") = -1 ENOENT (No such file or directory)
21470 exit_group(111)                   = ?
21470 +++ exited with 111 +++

(Hvis du er faret vild, kan du læse mit tidligere indlæg om *nix processtyring og skaller.) Så serveren PID 20629 modtog ikke tilladelse til at oprette en fil på stien /var/spool/cron/tmp/spool.21470.1573692319.854640. Mest sandsynligt er årsagen til dette de klassiske filsystemtilladelsesindstillinger. Lad os tjekke:

# ls -ld /var/spool/cron/tmp/
drwxr-xr-x 2 root root 4096 Nov  6 05:33 /var/spool/cron/tmp/
# ps u -p 20629
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
cron     20629  0.0  0.0   2276   752 ?        Ss   Nov14   0:00 unixserver -U /var/run/bcron-spool -- bcron-spool

Det er der, hunden ligger begravet! Serveren kører som en bruger cron, men kun root har tilladelse til at skrive til mappen /var/spool/cron/tmp/. Simpel kommando chown cron /var/spool/cron/tmp/ vilje styrke bcron fungere korrekt. (Hvis det ikke var problemet, så er den næste mest sandsynlige mistænkte et kernesikkerhedsmodul som SELinux eller AppArmor, så jeg ville tjekke kernemeddelelsesloggen med dmesg.)

I alt

Systemopkaldsspor kan være overvældende for en nybegynder, men jeg håber, jeg har vist, at de er en hurtig måde at fejlsøge en hel klasse af almindelige implementeringsproblemer. Forestil dig at prøve at fejlfinde en multiproces bcronved hjælp af en trin-for-trin debugger.

Parsing af sporingsresultater baglæns langs systemopkaldskæden kræver dygtighed, men som sagt, næsten altid, vha. strace, jeg får bare sporingsresultatet og leder efter fejl fra slutningen. Alligevel, strace hjælper mig med at spare en masse tid på fejlretning. Jeg håber, at det også vil være nyttigt for dig.

Kilde: www.habr.com

Tilføj en kommentar