From mboxrd@z Thu Jan 1 00:00:00 1970 From: Christian Robert Subject: What are thoses [btrfs-cache-nnn] kernel threads ? Date: Wed, 18 May 2011 22:37:17 -0400 Message-ID: <4DD4825D.4060706@polymtl.ca> Mime-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 To: linux-btrfs@vger.kernel.org Return-path: List-ID: hi, everyday at around 17:00, but today at 18:38 I start a multithread job (a la make -j4) who rsync 257 huge directory from a remote host to my machine (at kernel 2.6.39-rc7 since yesterday) below is the load average on the machine 2011-05-18 18:36 -> 0.00 0.11 0.13 1/218 1923 2011-05-18 18:37 -> 0.00 0.09 0.13 1/218 1923 2011-05-18 18:38 -> 0.42 0.17 0.15 1/240 2275 <- job started here 2011-05-18 18:39 -> 0.62 0.26 0.18 1/243 2287 2011-05-18 18:40 -> 1.78 0.64 0.32 1/244 2288 2011-05-18 18:41 -> 1.45 0.76 0.38 1/244 2297 2011-05-18 18:42 -> 1.94 1.02 0.49 1/244 2310 2011-05-18 18:43 -> 2.27 1.28 0.62 1/242 2325 2011-05-18 18:44 -> 2.39 1.45 0.71 1/247 2333 2011-05-18 18:45 -> 2.39 1.61 0.81 1/246 2359 2011-05-18 18:46 -> 3.22 1.95 0.98 1/248 2375 2011-05-18 18:47 -> 3.16 2.17 1.12 1/247 2386 2011-05-18 18:48 -> 3.40 2.39 1.25 1/249 2394 2011-05-18 18:49 -> 4.33 2.82 1.47 1/249 2395 2011-05-18 18:50 -> 3.93 3.01 1.63 1/246 2406 2011-05-18 18:51 -> 3.81 3.14 1.75 1/248 2410 2011-05-18 18:52 -> 3.92 3.32 1.90 1/247 2417 2011-05-18 18:53 -> 2.62 3.06 1.90 1/246 2431 2011-05-18 18:54 -> 3.52 3.22 2.03 1/248 2433 2011-05-18 18:55 -> 3.84 3.38 2.16 1/247 2439 2011-05-18 18:56 -> 2.91 3.26 2.20 1/245 2450 2011-05-18 18:57 -> 2.75 3.11 2.22 1/248 2457 2011-05-18 18:58 -> 3.59 3.29 2.33 1/248 2458 2011-05-18 18:59 -> 3.41 3.30 2.40 1/248 2468 2011-05-18 19:00 -> 3.76 3.40 2.49 1/247 2477 2011-05-18 19:01 -> 4.28 3.60 2.61 1/248 2488 2011-05-18 19:02 -> 4.06 3.67 2.70 1/247 2502 2011-05-18 19:03 -> 2.16 3.21 2.60 1/244 2515 2011-05-18 19:04 -> 2.81 3.17 2.62 1/247 2518 2011-05-18 19:05 -> 3.23 3.24 2.68 1/246 2522 2011-05-18 19:06 -> 3.53 3.32 2.74 1/246 2544 2011-05-18 19:07 -> 2.89 3.13 2.71 1/245 2550 2011-05-18 19:08 -> 3.68 3.28 2.79 1/247 2557 2011-05-18 19:09 -> 4.47 3.62 2.94 2/242 2571 2011-05-18 19:10 -> 3.20 3.39 2.90 1/244 2577 2011-05-18 19:11 -> 5.35 4.03 3.16 1/244 2584 2011-05-18 19:12 -> 5.07 4.20 3.26 3/245 2588 2011-05-18 19:13 -> 2.69 3.72 3.16 1/241 2602 2011-05-18 19:14 -> 3.37 3.70 3.19 1/244 2605 2011-05-18 19:15 -> 3.55 3.71 3.22 1/242 2611 2011-05-18 19:16 -> 2.94 3.48 3.18 1/243 2621 2011-05-18 19:17 -> 3.15 3.45 3.19 1/241 2630 2011-05-18 19:18 -> 3.02 3.37 3.17 1/242 2639 2011-05-18 19:19 -> 3.47 3.40 3.19 1/243 2649 2011-05-18 19:20 -> 3.71 3.46 3.23 1/243 2650 2011-05-18 19:21 -> 2.64 3.22 3.16 1/241 2664 2011-05-18 19:22 -> 3.48 3.31 3.19 1/244 2671 2011-05-18 19:23 -> 4.57 3.63 3.31 1/243 2675 2011-05-18 19:24 -> 4.06 3.66 3.34 1/242 2684 2011-05-18 19:25 -> 5.34 4.06 3.49 1/250 2699 2011-05-18 19:26 -> 6.18 4.57 3.71 1/244 2707 2011-05-18 19:27 -> 5.21 4.54 3.75 1/244 2711 2011-05-18 19:28 -> 4.17 4.37 3.74 1/244 2721 2011-05-18 19:29 -> 4.14 4.34 3.77 1/243 2728 2011-05-18 19:30 -> 4.52 4.40 3.82 1/243 2734 2011-05-18 19:31 -> 4.74 4.50 3.90 1/244 2743 2011-05-18 19:32 -> 5.09 4.60 3.97 3/244 2754 2011-05-18 19:33 -> 4.59 4.60 4.01 1/242 2765 2011-05-18 19:34 -> 4.39 4.53 4.02 1/243 2769 2011-05-18 19:35 -> 4.75 4.60 4.08 1/243 2773 2011-05-18 19:36 -> 4.98 4.66 4.13 2/245 2783 2011-05-18 19:37 -> 4.29 4.55 4.13 1/245 2797 2011-05-18 19:38 -> 7.16 5.27 4.39 1/243 2809 2011-05-18 19:39 -> 6.31 5.31 4.46 1/247 2815 2011-05-18 19:40 -> 6.29 5.40 4.54 1/251 2827 2011-05-18 19:41 -> 6.31 5.66 4.69 2/245 2838 2011-05-18 19:42 -> 4.43 5.25 4.61 1/243 2848 2011-05-18 19:43 -> 5.13 5.30 4.67 1/247 2856 2011-05-18 19:44 -> 5.39 5.31 4.71 1/243 2866 2011-05-18 19:45 -> 3.95 4.94 4.62 2/242 2874 2011-05-18 19:46 -> 4.59 4.99 4.66 1/243 2884 2011-05-18 19:47 -> 4.97 5.06 4.71 1/243 2889 2011-05-18 19:48 -> 5.51 5.25 4.79 1/245 2899 2011-05-18 19:49 -> 5.19 5.22 4.82 1/242 2905 2011-05-18 19:50 -> 5.21 5.18 4.82 2/246 2911 2011-05-18 19:51 -> 6.80 5.55 4.97 1/248 2918 2011-05-18 19:52 -> 6.11 5.67 5.05 1/241 2924 2011-05-18 19:53 -> 5.89 5.72 5.11 3/240 2938 2011-05-18 19:54 -> 3.96 5.20 4.96 1/241 2944 2011-05-18 19:55 -> 5.03 5.32 5.02 1/244 2952 2011-05-18 19:56 -> 4.81 5.22 5.01 1/243 2954 2011-05-18 19:57 -> 5.01 5.22 5.03 1/242 2958 2011-05-18 19:58 -> 4.82 5.15 5.02 1/242 2965 2011-05-18 19:59 -> 4.37 4.99 4.98 1/241 2978 2011-05-18 20:00 -> 4.93 4.98 4.97 3/243 2985 2011-05-18 20:01 -> 4.56 4.85 4.93 1/243 2995 2011-05-18 20:02 -> 4.41 4.76 4.89 2/243 3012 2011-05-18 20:03 -> 4.06 4.59 4.82 2/245 3022 2011-05-18 20:04 -> 3.94 4.47 4.77 2/243 3029 2011-05-18 20:05 -> 4.85 4.60 4.79 1/243 3034 2011-05-18 20:06 -> 4.90 4.71 4.82 1/242 3047 2011-05-18 20:07 -> 4.50 4.61 4.78 2/244 3055 2011-05-18 20:08 -> 4.06 4.48 4.72 2/245 3061 2011-05-18 20:09 -> 4.34 4.52 4.72 1/242 3070 2011-05-18 20:10 -> 4.95 4.63 4.75 1/246 3077 2011-05-18 20:11 -> 4.27 4.55 4.72 1/241 3089 2011-05-18 20:12 -> 4.44 4.58 4.72 1/241 3098 2011-05-18 20:13 -> 5.13 4.77 4.78 1/242 3104 2011-05-18 20:14 -> 4.20 4.56 4.70 1/245 3118 2011-05-18 20:15 -> 4.20 4.51 4.68 1/241 3128 2011-05-18 20:16 -> 4.43 4.52 4.67 1/244 3137 2011-05-18 20:17 -> 4.96 4.71 4.73 1/244 3146 2011-05-18 20:18 -> 5.36 4.85 4.78 3/246 3151 2011-05-18 20:19 -> 4.25 4.65 4.72 1/245 3165 2011-05-18 20:20 -> 4.75 4.77 4.76 1/243 3173 2011-05-18 20:21 -> 5.42 4.94 4.81 1/241 3187 2011-05-18 20:22 -> 3.58 4.49 4.67 3/243 3196 2011-05-18 20:23 -> 4.27 4.54 4.67 1/243 3199 2011-05-18 20:24 -> 4.26 4.53 4.67 1/243 3212 2011-05-18 20:25 -> 4.68 4.59 4.68 1/244 3224 2011-05-18 20:26 -> 4.50 4.59 4.68 1/242 3231 2011-05-18 20:27 -> 5.09 4.74 4.72 1/243 3243 2011-05-18 20:28 -> 5.09 4.76 4.72 1/246 3256 2011-05-18 20:29 -> 5.30 4.87 4.76 1/243 3260 2011-05-18 20:30 -> 6.75 5.37 4.94 1/244 3270 2011-05-18 20:31 -> 8.16 5.93 5.16 1/247 3286 2011-05-18 20:32 -> 8.30 6.34 5.34 2/242 3302 2011-05-18 20:33 -> 5.72 5.95 5.27 1/242 3303 2011-05-18 20:34 -> 3.55 5.33 5.10 2/240 3313 2011-05-18 20:35 -> 3.39 4.93 4.98 1/241 3322 2011-05-18 20:36 -> 3.59 4.69 4.89 1/242 3323 2011-05-18 20:37 -> 2.67 4.24 4.72 1/242 3335 2011-05-18 20:38 -> 3.42 4.18 4.67 1/241 3338 2011-05-18 20:39 -> 2.92 3.91 4.55 2/241 3346 2011-05-18 20:40 -> 3.23 3.80 4.47 1/242 3351 2011-05-18 20:41 -> 4.63 4.12 4.54 1/240 3361 2011-05-18 20:42 -> 5.07 4.33 4.59 1/242 3370 2011-05-18 20:43 -> 4.46 4.31 4.57 1/241 3376 2011-05-18 20:44 -> 5.27 4.52 4.62 2/246 3382 2011-05-18 20:45 -> 4.89 4.56 4.63 1/240 3396 2011-05-18 20:46 -> 4.83 4.55 4.62 2/242 3406 2011-05-18 20:47 -> 4.75 4.58 4.62 1/243 3410 2011-05-18 20:48 -> 5.25 4.75 4.68 1/243 3417 2011-05-18 20:49 -> 4.40 4.65 4.65 9/243 3429 2011-05-18 20:50 -> 5.32 4.87 4.73 3/242 3437 2011-05-18 20:51 -> 5.48 4.99 4.78 1/243 3443 2011-05-18 20:52 -> 5.81 5.24 4.88 2/244 3457 2011-05-18 20:53 -> 5.37 5.24 4.90 1/245 3464 2011-05-18 20:54 -> 7.99 5.93 5.16 1/252 3478 2011-05-18 20:55 -> 7.36 6.24 5.32 1/245 3488 2011-05-18 20:56 -> 5.82 6.04 5.31 1/245 3500 2011-05-18 20:57 -> 5.21 5.83 5.28 1/246 3505 2011-05-18 20:58 -> 4.93 5.67 5.27 1/242 3505 2011-05-18 20:59 -> 5.36 5.74 5.32 1/240 3521 2011-05-18 21:00 -> 4.47 5.30 5.19 1/250 3537 2011-05-18 21:01 -> 7.26 6.10 5.48 2/244 3546 2011-05-18 21:02 -> 8.85 6.61 5.69 3/252 3566 2011-05-18 21:03 -> 7.53 6.64 5.76 1/243 3573 2011-05-18 21:04 -> 5.49 6.27 5.69 2/240 3584 2011-05-18 21:05 -> 6.65 6.40 5.77 1/243 3595 2011-05-18 21:06 -> 5.56 6.12 5.71 2/244 3600 2011-05-18 21:07 -> 6.28 6.23 5.78 3/242 3612 2011-05-18 21:08 -> 5.31 5.90 5.69 2/242 3625 2011-05-18 21:09 -> 5.84 5.98 5.73 2/244 3633 2011-05-18 21:10 -> 6.69 6.27 5.85 4/244 3648 2011-05-18 21:11 -> 9.35 6.96 6.10 1/246 3662 2011-05-18 21:12 -> 7.45 6.78 6.09 1/244 3671 2011-05-18 21:13 -> 8.69 7.14 6.25 1/251 3707 2011-05-18 21:14 -> 10.05 7.68 6.48 1/251 3732 here I received an email notification that the loadavg exceeded 10 2011-05-18 21:15 -> 6.69 7.16 6.38 1/248 3748 2011-05-18 21:16 -> 7.44 7.26 6.46 1/252 3762 2011-05-18 21:17 -> 8.09 7.67 6.67 1/244 3777 2011-05-18 21:18 -> 9.36 8.05 6.86 1/248 3808 2011-05-18 21:19 -> 6.53 7.48 6.74 2/246 3821 2011-05-18 21:20 -> 9.34 8.11 7.00 1/243 3848 2011-05-18 21:21 -> 7.57 7.73 6.93 1/245 3861 2011-05-18 21:22 -> 6.52 7.47 6.90 1/248 3883 2011-05-18 21:23 -> 8.71 7.82 7.05 3/254 3901 2011-05-18 21:24 -> 9.72 8.21 7.23 2/253 3918 2011-05-18 21:25 -> 9.95 8.46 7.37 1/252 3929 2011-05-18 21:26 -> 10.77 8.81 7.55 1/253 3939 2011-05-18 21:27 -> 10.62 9.08 7.72 1/253 3967 2011-05-18 21:28 -> 8.49 8.71 7.67 1/251 3985 2011-05-18 21:29 -> 9.76 8.89 7.79 12/256 3999 2011-05-18 21:30 -> 10.17 9.44 8.07 1/244 4012 2011-05-18 21:31 -> 8.35 8.96 7.98 1/255 4039 2011-05-18 21:32 -> 8.95 9.20 8.14 2/245 4045 2011-05-18 21:33 -> 8.63 9.20 8.21 1/244 4053 2011-05-18 21:34 -> 8.72 9.24 8.29 1/248 4075 2011-05-18 21:35 -> 10.09 9.48 8.43 1/253 4124 2011-05-18 21:36 -> 12.77 10.16 8.72 1/257 4170 2011-05-18 21:37 -> 8.47 9.39 8.55 1/251 4198 2011-05-18 21:38 -> 8.81 9.35 8.59 1/252 4211 2011-05-18 21:39 -> 8.14 9.09 8.55 2/246 4240 2011-05-18 21:40 -> 13.65 10.34 9.00 1/256 4276 2011-05-18 21:41 -> 9.54 9.66 8.85 2/252 4335 2011-05-18 21:42 -> 13.92 10.82 9.29 1/253 4369 2011-05-18 21:43 -> 9.13 10.16 9.17 1/241 4389 2011-05-18 21:44 -> 9.47 9.91 9.14 1/249 4431 2011-05-18 21:45 -> 10.61 10.07 9.24 1/257 4451 2011-05-18 21:46 -> 11.34 10.56 9.47 1/244 4456 Here I killed -stop the 4 rsync process 2011-05-18 21:47 -> 5.10 8.96 8.99 1/234 4456 2011-05-18 21:48 -> 1.94 7.35 8.44 2/243 4484 Here I killed -cont the 4 rsync process 2011-05-18 21:49 -> 2.43 6.44 8.05 1/246 4488 2011-05-18 21:50 -> 3.50 6.01 7.80 1/246 4488 2011-05-18 21:51 -> 3.18 5.49 7.51 8/243 4498 2011-05-18 21:52 -> 3.50 5.15 7.27 1/244 4503 2011-05-18 21:53 -> 3.83 4.93 7.06 1/245 4504 2011-05-18 21:54 -> 3.02 4.52 6.79 1/243 4514 2011-05-18 21:55 -> 3.37 4.32 6.57 2/245 4520 2011-05-18 21:56 -> 3.51 4.17 6.38 2/245 4524 2011-05-18 21:57 -> 3.15 3.97 6.17 1/243 4542 2011-05-18 21:58 -> 3.67 3.96 6.03 2/244 4543 2011-05-18 21:59 -> 3.55 3.88 5.87 1/243 4558 2011-05-18 22:00 -> 2.88 3.60 5.65 1/244 4563 2011-05-18 22:01 -> 3.29 3.62 5.53 1/245 4568 2011-05-18 22:02 -> 3.53 3.63 5.42 3/247 4582 2011-05-18 22:03 -> 3.17 3.54 5.27 2/244 4592 2011-05-18 22:04 -> 3.27 3.45 5.13 1/246 4598 2011-05-18 22:05 -> 3.64 3.53 5.06 1/245 4601 2011-05-18 22:06 -> 2.68 3.28 4.88 2/244 4612 2011-05-18 22:07 -> 3.25 3.33 4.79 1/245 4614 2011-05-18 22:08 -> 3.95 3.51 4.76 1/246 4615 2011-05-18 22:09 -> 3.23 3.43 4.66 1/242 4624 2011-05-18 22:10 -> 3.08 3.34 4.55 1/245 4631 2011-05-18 22:11 -> 3.46 3.43 4.51 1/244 4643 2011-05-18 22:12 -> 3.90 3.55 4.48 1/243 4658 a "top" when at loadavg 10+ show something like 8 or 10 kernel threads named btrfs-cache-* all in "D" status. I'm no expert at all but I think thoses kthreads lack a bit of priority to finish the job they have to do. I will let you judge on that. I've seen that behavior with older kernels too (plain fedora-14) It does not happen often, may be one time every few weeks. When it happen, the loadavg increase endlessly until all the rsync prosess finish. Then loadavg drop to zero. Christian Robert, Poly.