Why is the system call disconnecting so slowly?
#include <unistd.h>
#include <stdio.h>
void dump_log(int size){
char cmd[1024];
snprintf(cmd, sizeof(cmd)/sizeof(cmd[0]), "dd if=/dev/zero of=from.bin bs=1024 count=%d", size);
int ret = system(cmd);
if (ret<0){
perror("system");
}
}
int main(){
const char *filepath = "from.bin";
while(1){
dump_log(1024*100);
sleep(10);
unlink(filepath);
}
return 0;
}
strace -T ./a.out
show this:
unlink("from.bin") = 0 <0.019916>
detach file (100M) take 19ms, what happens if detach file? why so slow?
system info: linux 3.13.0-57-generic, Ubuntu 14.04.2 LTS, ext4
source to share
If you have a huge file to unlink (2) , the kernel will not unlock the index until all block pointers have been returned to the free list. You can check the time difference by making a second link (which will only disconnect to release the link you delete without releasing any block). By spec, the code that frees all those blocks is your process (well, it runs in kernel mode, not usermode, but there is no reserved process for returning blocks to the free list), and it won't come back until all the blocks have been released.
Example: (change)
The following code illustrates this:
#include <errno.h>
#include <getopt.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <time.h>
#define D(X) "%s:%d:%s: " X, __FILE__, __LINE__, __func__
int main(int argc, char **argv)
{
int opt, i;
while ((opt = getopt(argc, argv, "")) != EOF) {
switch (opt) {
} /* switch */
} /* while */
argc -= optind; argv += optind;
for (i = 0; i < argc; i++) {
struct timespec now, then;
int res;
res = clock_gettime(CLOCK_THREAD_CPUTIME_ID, &now);
if (res < 0) {
fprintf(stderr,
D("ERROR: %s (errno = %d)\n"),
strerror(errno), errno);
exit(EXIT_FAILURE);
} /* if */
unlink(argv[i]);
res = clock_gettime(CLOCK_THREAD_CPUTIME_ID, &then);
if (res < 0) {
fprintf(stderr, D("ERROR: %s (errno = %d)\n"),
strerror(errno), errno);
exit(EXIT_FAILURE);
} /* if */
then.tv_nsec -= now.tv_nsec;
then.tv_sec -= now.tv_sec;
if (then.tv_nsec < 0) {
then.tv_nsec += 1000000000L;
then.tv_sec--;
} /* if */
printf(D("%s: %d.%09d s. (CPU time)\n"),
argv[i], then.tv_sec, then.tv_nsec);
} /* for */
exit(EXIT_SUCCESS);
} /* main */
Then I create a 2Gb file using this command:
$ yes | dd of=pepe bs=1M iflag=fullblock count=2048
Then I make 32 links to this file:
i=0
while [ "$i" -lt 32 ]
do ln pepe pepe$i
i=$(expr $i + 1)
done
Then I run the following command (which only shows the cpu time):
$ unlink pepe[0-9]* pepe
unlink.c:47:main: pepe0: 0.000074272 s. (CPU time)
unlink.c:47:main: pepe1: 0.000022722 s. (CPU time)
unlink.c:47:main: pepe10: 0.000015034 s. (CPU time)
unlink.c:47:main: pepe11: 0.000013254 s. (CPU time)
unlink.c:47:main: pepe12: 0.000012827 s. (CPU time)
unlink.c:47:main: pepe13: 0.000012462 s. (CPU time)
unlink.c:47:main: pepe14: 0.000012241 s. (CPU time)
unlink.c:47:main: pepe15: 0.000012753 s. (CPU time)
unlink.c:47:main: pepe16: 0.000012517 s. (CPU time)
unlink.c:47:main: pepe17: 0.000012245 s. (CPU time)
unlink.c:47:main: pepe18: 0.000013104 s. (CPU time)
unlink.c:47:main: pepe19: 0.000012491 s. (CPU time)
unlink.c:47:main: pepe2: 0.000012662 s. (CPU time)
unlink.c:47:main: pepe20: 0.000012606 s. (CPU time)
unlink.c:47:main: pepe21: 0.000012803 s. (CPU time)
unlink.c:47:main: pepe22: 0.000012597 s. (CPU time)
unlink.c:47:main: pepe23: 0.000012391 s. (CPU time)
unlink.c:47:main: pepe24: 0.000012582 s. (CPU time)
unlink.c:47:main: pepe25: 0.000012557 s. (CPU time)
unlink.c:47:main: pepe26: 0.000012386 s. (CPU time)
unlink.c:47:main: pepe27: 0.000012261 s. (CPU time)
unlink.c:47:main: pepe28: 0.000012245 s. (CPU time)
unlink.c:47:main: pepe29: 0.000012351 s. (CPU time)
unlink.c:47:main: pepe3: 0.000011940 s. (CPU time)
unlink.c:47:main: pepe30: 0.000013003 s. (CPU time)
unlink.c:47:main: pepe31: 0.000012231 s. (CPU time)
unlink.c:47:main: pepe4: 0.000012777 s. (CPU time)
unlink.c:47:main: pepe5: 0.000012546 s. (CPU time)
unlink.c:47:main: pepe6: 0.000012461 s. (CPU time)
unlink.c:47:main: pepe7: 0.000013129 s. (CPU time)
unlink.c:47:main: pepe8: 0.000012311 s. (CPU time)
unlink.c:47:main: pepe9: 0.000012446 s. (CPU time)
unlink.c:47:main: pepe: 0.195457587 s. (CPU time)
As you can see, everything except the last connection takes about 12 microseconds, but the last one is almost two tenths of a second.
source to share