diff options
author | David Teigland <teigland@redhat.com> | 2011-03-28 15:17:26 -0400 |
---|---|---|
committer | David Teigland <teigland@redhat.com> | 2011-04-01 15:19:06 -0400 |
commit | c6ff669bac5c409f4cb74366248f51b73f7d6feb (patch) | |
tree | 14c4b7dc943a7dde8fd6d80bc9d149dadc0d59b8 /fs | |
parent | 4bcad6c1ef53a9a0224f4654ceb3b9030d0769ec (diff) |
dlm: delayed reply message warning
Add an option (disabled by default) to print a warning message
when a lock has been waiting a configurable amount of time for
a reply message from another node. This is mainly for debugging.
Signed-off-by: David Teigland <teigland@redhat.com>
Diffstat (limited to 'fs')
-rw-r--r-- | fs/dlm/config.c | 9 | ||||
-rw-r--r-- | fs/dlm/config.h | 1 | ||||
-rw-r--r-- | fs/dlm/dlm_internal.h | 2 | ||||
-rw-r--r-- | fs/dlm/lock.c | 100 | ||||
-rw-r--r-- | fs/dlm/lock.h | 1 | ||||
-rw-r--r-- | fs/dlm/lockspace.c | 6 |
6 files changed, 108 insertions, 11 deletions
diff --git a/fs/dlm/config.c b/fs/dlm/config.c index 0d329ff8ed4c..9b026ea8baa9 100644 --- a/fs/dlm/config.c +++ b/fs/dlm/config.c | |||
@@ -100,6 +100,7 @@ struct dlm_cluster { | |||
100 | unsigned int cl_log_debug; | 100 | unsigned int cl_log_debug; |
101 | unsigned int cl_protocol; | 101 | unsigned int cl_protocol; |
102 | unsigned int cl_timewarn_cs; | 102 | unsigned int cl_timewarn_cs; |
103 | unsigned int cl_waitwarn_us; | ||
103 | }; | 104 | }; |
104 | 105 | ||
105 | enum { | 106 | enum { |
@@ -114,6 +115,7 @@ enum { | |||
114 | CLUSTER_ATTR_LOG_DEBUG, | 115 | CLUSTER_ATTR_LOG_DEBUG, |
115 | CLUSTER_ATTR_PROTOCOL, | 116 | CLUSTER_ATTR_PROTOCOL, |
116 | CLUSTER_ATTR_TIMEWARN_CS, | 117 | CLUSTER_ATTR_TIMEWARN_CS, |
118 | CLUSTER_ATTR_WAITWARN_US, | ||
117 | }; | 119 | }; |
118 | 120 | ||
119 | struct cluster_attribute { | 121 | struct cluster_attribute { |
@@ -166,6 +168,7 @@ CLUSTER_ATTR(scan_secs, 1); | |||
166 | CLUSTER_ATTR(log_debug, 0); | 168 | CLUSTER_ATTR(log_debug, 0); |
167 | CLUSTER_ATTR(protocol, 0); | 169 | CLUSTER_ATTR(protocol, 0); |
168 | CLUSTER_ATTR(timewarn_cs, 1); | 170 | CLUSTER_ATTR(timewarn_cs, 1); |
171 | CLUSTER_ATTR(waitwarn_us, 0); | ||
169 | 172 | ||
170 | static struct configfs_attribute *cluster_attrs[] = { | 173 | static struct configfs_attribute *cluster_attrs[] = { |
171 | [CLUSTER_ATTR_TCP_PORT] = &cluster_attr_tcp_port.attr, | 174 | [CLUSTER_ATTR_TCP_PORT] = &cluster_attr_tcp_port.attr, |
@@ -179,6 +182,7 @@ static struct configfs_attribute *cluster_attrs[] = { | |||
179 | [CLUSTER_ATTR_LOG_DEBUG] = &cluster_attr_log_debug.attr, | 182 | [CLUSTER_ATTR_LOG_DEBUG] = &cluster_attr_log_debug.attr, |
180 | [CLUSTER_ATTR_PROTOCOL] = &cluster_attr_protocol.attr, | 183 | [CLUSTER_ATTR_PROTOCOL] = &cluster_attr_protocol.attr, |
181 | [CLUSTER_ATTR_TIMEWARN_CS] = &cluster_attr_timewarn_cs.attr, | 184 | [CLUSTER_ATTR_TIMEWARN_CS] = &cluster_attr_timewarn_cs.attr, |
185 | [CLUSTER_ATTR_WAITWARN_US] = &cluster_attr_waitwarn_us.attr, | ||
182 | NULL, | 186 | NULL, |
183 | }; | 187 | }; |
184 | 188 | ||
@@ -439,6 +443,7 @@ static struct config_group *make_cluster(struct config_group *g, | |||
439 | cl->cl_log_debug = dlm_config.ci_log_debug; | 443 | cl->cl_log_debug = dlm_config.ci_log_debug; |
440 | cl->cl_protocol = dlm_config.ci_protocol; | 444 | cl->cl_protocol = dlm_config.ci_protocol; |
441 | cl->cl_timewarn_cs = dlm_config.ci_timewarn_cs; | 445 | cl->cl_timewarn_cs = dlm_config.ci_timewarn_cs; |
446 | cl->cl_waitwarn_us = dlm_config.ci_waitwarn_us; | ||
442 | 447 | ||
443 | space_list = &sps->ss_group; | 448 | space_list = &sps->ss_group; |
444 | comm_list = &cms->cs_group; | 449 | comm_list = &cms->cs_group; |
@@ -986,6 +991,7 @@ int dlm_our_addr(struct sockaddr_storage *addr, int num) | |||
986 | #define DEFAULT_LOG_DEBUG 0 | 991 | #define DEFAULT_LOG_DEBUG 0 |
987 | #define DEFAULT_PROTOCOL 0 | 992 | #define DEFAULT_PROTOCOL 0 |
988 | #define DEFAULT_TIMEWARN_CS 500 /* 5 sec = 500 centiseconds */ | 993 | #define DEFAULT_TIMEWARN_CS 500 /* 5 sec = 500 centiseconds */ |
994 | #define DEFAULT_WAITWARN_US 0 | ||
989 | 995 | ||
990 | struct dlm_config_info dlm_config = { | 996 | struct dlm_config_info dlm_config = { |
991 | .ci_tcp_port = DEFAULT_TCP_PORT, | 997 | .ci_tcp_port = DEFAULT_TCP_PORT, |
@@ -998,6 +1004,7 @@ struct dlm_config_info dlm_config = { | |||
998 | .ci_scan_secs = DEFAULT_SCAN_SECS, | 1004 | .ci_scan_secs = DEFAULT_SCAN_SECS, |
999 | .ci_log_debug = DEFAULT_LOG_DEBUG, | 1005 | .ci_log_debug = DEFAULT_LOG_DEBUG, |
1000 | .ci_protocol = DEFAULT_PROTOCOL, | 1006 | .ci_protocol = DEFAULT_PROTOCOL, |
1001 | .ci_timewarn_cs = DEFAULT_TIMEWARN_CS | 1007 | .ci_timewarn_cs = DEFAULT_TIMEWARN_CS, |
1008 | .ci_waitwarn_us = DEFAULT_WAITWARN_US | ||
1002 | }; | 1009 | }; |
1003 | 1010 | ||
diff --git a/fs/dlm/config.h b/fs/dlm/config.h index 4f1d6fce58c5..dd0ce24d5a80 100644 --- a/fs/dlm/config.h +++ b/fs/dlm/config.h | |||
@@ -28,6 +28,7 @@ struct dlm_config_info { | |||
28 | int ci_log_debug; | 28 | int ci_log_debug; |
29 | int ci_protocol; | 29 | int ci_protocol; |
30 | int ci_timewarn_cs; | 30 | int ci_timewarn_cs; |
31 | int ci_waitwarn_us; | ||
31 | }; | 32 | }; |
32 | 33 | ||
33 | extern struct dlm_config_info dlm_config; | 34 | extern struct dlm_config_info dlm_config; |
diff --git a/fs/dlm/dlm_internal.h b/fs/dlm/dlm_internal.h index b94204913011..6a92478fe1f1 100644 --- a/fs/dlm/dlm_internal.h +++ b/fs/dlm/dlm_internal.h | |||
@@ -245,6 +245,7 @@ struct dlm_lkb { | |||
245 | 245 | ||
246 | int8_t lkb_wait_type; /* type of reply waiting for */ | 246 | int8_t lkb_wait_type; /* type of reply waiting for */ |
247 | int8_t lkb_wait_count; | 247 | int8_t lkb_wait_count; |
248 | int lkb_wait_nodeid; /* for debugging */ | ||
248 | 249 | ||
249 | struct list_head lkb_idtbl_list; /* lockspace lkbtbl */ | 250 | struct list_head lkb_idtbl_list; /* lockspace lkbtbl */ |
250 | struct list_head lkb_statequeue; /* rsb g/c/w list */ | 251 | struct list_head lkb_statequeue; /* rsb g/c/w list */ |
@@ -254,6 +255,7 @@ struct dlm_lkb { | |||
254 | struct list_head lkb_ownqueue; /* list of locks for a process */ | 255 | struct list_head lkb_ownqueue; /* list of locks for a process */ |
255 | struct list_head lkb_time_list; | 256 | struct list_head lkb_time_list; |
256 | ktime_t lkb_timestamp; | 257 | ktime_t lkb_timestamp; |
258 | ktime_t lkb_wait_time; | ||
257 | unsigned long lkb_timeout_cs; | 259 | unsigned long lkb_timeout_cs; |
258 | 260 | ||
259 | struct dlm_callback lkb_callbacks[DLM_CALLBACKS_SIZE]; | 261 | struct dlm_callback lkb_callbacks[DLM_CALLBACKS_SIZE]; |
diff --git a/fs/dlm/lock.c b/fs/dlm/lock.c index 04b8c449303f..e3c864120371 100644 --- a/fs/dlm/lock.c +++ b/fs/dlm/lock.c | |||
@@ -799,10 +799,84 @@ static int msg_reply_type(int mstype) | |||
799 | return -1; | 799 | return -1; |
800 | } | 800 | } |
801 | 801 | ||
802 | static int nodeid_warned(int nodeid, int num_nodes, int *warned) | ||
803 | { | ||
804 | int i; | ||
805 | |||
806 | for (i = 0; i < num_nodes; i++) { | ||
807 | if (!warned[i]) { | ||
808 | warned[i] = nodeid; | ||
809 | return 0; | ||
810 | } | ||
811 | if (warned[i] == nodeid) | ||
812 | return 1; | ||
813 | } | ||
814 | return 0; | ||
815 | } | ||
816 | |||
817 | void dlm_scan_waiters(struct dlm_ls *ls) | ||
818 | { | ||
819 | struct dlm_lkb *lkb; | ||
820 | ktime_t zero = ktime_set(0, 0); | ||
821 | s64 us; | ||
822 | s64 debug_maxus = 0; | ||
823 | u32 debug_scanned = 0; | ||
824 | u32 debug_expired = 0; | ||
825 | int num_nodes = 0; | ||
826 | int *warned = NULL; | ||
827 | |||
828 | if (!dlm_config.ci_waitwarn_us) | ||
829 | return; | ||
830 | |||
831 | mutex_lock(&ls->ls_waiters_mutex); | ||
832 | |||
833 | list_for_each_entry(lkb, &ls->ls_waiters, lkb_wait_reply) { | ||
834 | if (ktime_equal(lkb->lkb_wait_time, zero)) | ||
835 | continue; | ||
836 | |||
837 | debug_scanned++; | ||
838 | |||
839 | us = ktime_to_us(ktime_sub(ktime_get(), lkb->lkb_wait_time)); | ||
840 | |||
841 | if (us < dlm_config.ci_waitwarn_us) | ||
842 | continue; | ||
843 | |||
844 | lkb->lkb_wait_time = zero; | ||
845 | |||
846 | debug_expired++; | ||
847 | if (us > debug_maxus) | ||
848 | debug_maxus = us; | ||
849 | |||
850 | if (!num_nodes) { | ||
851 | num_nodes = ls->ls_num_nodes; | ||
852 | warned = kmalloc(GFP_KERNEL, num_nodes * sizeof(int)); | ||
853 | if (warned) | ||
854 | memset(warned, 0, num_nodes * sizeof(int)); | ||
855 | } | ||
856 | if (!warned) | ||
857 | continue; | ||
858 | if (nodeid_warned(lkb->lkb_wait_nodeid, num_nodes, warned)) | ||
859 | continue; | ||
860 | |||
861 | log_error(ls, "waitwarn %x %lld %d us check connection to " | ||
862 | "node %d", lkb->lkb_id, (long long)us, | ||
863 | dlm_config.ci_waitwarn_us, lkb->lkb_wait_nodeid); | ||
864 | } | ||
865 | mutex_unlock(&ls->ls_waiters_mutex); | ||
866 | |||
867 | if (warned) | ||
868 | kfree(warned); | ||
869 | |||
870 | if (debug_expired) | ||
871 | log_debug(ls, "scan_waiters %u warn %u over %d us max %lld us", | ||
872 | debug_scanned, debug_expired, | ||
873 | dlm_config.ci_waitwarn_us, (long long)debug_maxus); | ||
874 | } | ||
875 | |||
802 | /* add/remove lkb from global waiters list of lkb's waiting for | 876 | /* add/remove lkb from global waiters list of lkb's waiting for |
803 | a reply from a remote node */ | 877 | a reply from a remote node */ |
804 | 878 | ||
805 | static int add_to_waiters(struct dlm_lkb *lkb, int mstype) | 879 | static int add_to_waiters(struct dlm_lkb *lkb, int mstype, int to_nodeid) |
806 | { | 880 | { |
807 | struct dlm_ls *ls = lkb->lkb_resource->res_ls; | 881 | struct dlm_ls *ls = lkb->lkb_resource->res_ls; |
808 | int error = 0; | 882 | int error = 0; |
@@ -842,6 +916,8 @@ static int add_to_waiters(struct dlm_lkb *lkb, int mstype) | |||
842 | 916 | ||
843 | lkb->lkb_wait_count++; | 917 | lkb->lkb_wait_count++; |
844 | lkb->lkb_wait_type = mstype; | 918 | lkb->lkb_wait_type = mstype; |
919 | lkb->lkb_wait_time = ktime_get(); | ||
920 | lkb->lkb_wait_nodeid = to_nodeid; /* for debugging */ | ||
845 | hold_lkb(lkb); | 921 | hold_lkb(lkb); |
846 | list_add(&lkb->lkb_wait_reply, &ls->ls_waiters); | 922 | list_add(&lkb->lkb_wait_reply, &ls->ls_waiters); |
847 | out: | 923 | out: |
@@ -1157,6 +1233,16 @@ void dlm_adjust_timeouts(struct dlm_ls *ls) | |||
1157 | list_for_each_entry(lkb, &ls->ls_timeout, lkb_time_list) | 1233 | list_for_each_entry(lkb, &ls->ls_timeout, lkb_time_list) |
1158 | lkb->lkb_timestamp = ktime_add_us(lkb->lkb_timestamp, adj_us); | 1234 | lkb->lkb_timestamp = ktime_add_us(lkb->lkb_timestamp, adj_us); |
1159 | mutex_unlock(&ls->ls_timeout_mutex); | 1235 | mutex_unlock(&ls->ls_timeout_mutex); |
1236 | |||
1237 | if (!dlm_config.ci_waitwarn_us) | ||
1238 | return; | ||
1239 | |||
1240 | mutex_lock(&ls->ls_waiters_mutex); | ||
1241 | list_for_each_entry(lkb, &ls->ls_waiters, lkb_wait_reply) { | ||
1242 | if (ktime_to_us(lkb->lkb_wait_time)) | ||
1243 | lkb->lkb_wait_time = ktime_get(); | ||
1244 | } | ||
1245 | mutex_unlock(&ls->ls_waiters_mutex); | ||
1160 | } | 1246 | } |
1161 | 1247 | ||
1162 | /* lkb is master or local copy */ | 1248 | /* lkb is master or local copy */ |
@@ -2844,12 +2930,12 @@ static int send_common(struct dlm_rsb *r, struct dlm_lkb *lkb, int mstype) | |||
2844 | struct dlm_mhandle *mh; | 2930 | struct dlm_mhandle *mh; |
2845 | int to_nodeid, error; | 2931 | int to_nodeid, error; |
2846 | 2932 | ||
2847 | error = add_to_waiters(lkb, mstype); | 2933 | to_nodeid = r->res_nodeid; |
2934 | |||
2935 | error = add_to_waiters(lkb, mstype, to_nodeid); | ||
2848 | if (error) | 2936 | if (error) |
2849 | return error; | 2937 | return error; |
2850 | 2938 | ||
2851 | to_nodeid = r->res_nodeid; | ||
2852 | |||
2853 | error = create_message(r, lkb, to_nodeid, mstype, &ms, &mh); | 2939 | error = create_message(r, lkb, to_nodeid, mstype, &ms, &mh); |
2854 | if (error) | 2940 | if (error) |
2855 | goto fail; | 2941 | goto fail; |
@@ -2951,12 +3037,12 @@ static int send_lookup(struct dlm_rsb *r, struct dlm_lkb *lkb) | |||
2951 | struct dlm_mhandle *mh; | 3037 | struct dlm_mhandle *mh; |
2952 | int to_nodeid, error; | 3038 | int to_nodeid, error; |
2953 | 3039 | ||
2954 | error = add_to_waiters(lkb, DLM_MSG_LOOKUP); | 3040 | to_nodeid = dlm_dir_nodeid(r); |
3041 | |||
3042 | error = add_to_waiters(lkb, DLM_MSG_LOOKUP, to_nodeid); | ||
2955 | if (error) | 3043 | if (error) |
2956 | return error; | 3044 | return error; |
2957 | 3045 | ||
2958 | to_nodeid = dlm_dir_nodeid(r); | ||
2959 | |||
2960 | error = create_message(r, NULL, to_nodeid, DLM_MSG_LOOKUP, &ms, &mh); | 3046 | error = create_message(r, NULL, to_nodeid, DLM_MSG_LOOKUP, &ms, &mh); |
2961 | if (error) | 3047 | if (error) |
2962 | goto fail; | 3048 | goto fail; |
diff --git a/fs/dlm/lock.h b/fs/dlm/lock.h index 88e93c80cc22..265017a7c3e7 100644 --- a/fs/dlm/lock.h +++ b/fs/dlm/lock.h | |||
@@ -24,6 +24,7 @@ int dlm_put_lkb(struct dlm_lkb *lkb); | |||
24 | void dlm_scan_rsbs(struct dlm_ls *ls); | 24 | void dlm_scan_rsbs(struct dlm_ls *ls); |
25 | int dlm_lock_recovery_try(struct dlm_ls *ls); | 25 | int dlm_lock_recovery_try(struct dlm_ls *ls); |
26 | void dlm_unlock_recovery(struct dlm_ls *ls); | 26 | void dlm_unlock_recovery(struct dlm_ls *ls); |
27 | void dlm_scan_waiters(struct dlm_ls *ls); | ||
27 | void dlm_scan_timeout(struct dlm_ls *ls); | 28 | void dlm_scan_timeout(struct dlm_ls *ls); |
28 | void dlm_adjust_timeouts(struct dlm_ls *ls); | 29 | void dlm_adjust_timeouts(struct dlm_ls *ls); |
29 | 30 | ||
diff --git a/fs/dlm/lockspace.c b/fs/dlm/lockspace.c index f994a7dfda85..14cbf4099753 100644 --- a/fs/dlm/lockspace.c +++ b/fs/dlm/lockspace.c | |||
@@ -243,7 +243,6 @@ static struct dlm_ls *find_ls_to_scan(void) | |||
243 | static int dlm_scand(void *data) | 243 | static int dlm_scand(void *data) |
244 | { | 244 | { |
245 | struct dlm_ls *ls; | 245 | struct dlm_ls *ls; |
246 | int timeout_jiffies = dlm_config.ci_scan_secs * HZ; | ||
247 | 246 | ||
248 | while (!kthread_should_stop()) { | 247 | while (!kthread_should_stop()) { |
249 | ls = find_ls_to_scan(); | 248 | ls = find_ls_to_scan(); |
@@ -252,13 +251,14 @@ static int dlm_scand(void *data) | |||
252 | ls->ls_scan_time = jiffies; | 251 | ls->ls_scan_time = jiffies; |
253 | dlm_scan_rsbs(ls); | 252 | dlm_scan_rsbs(ls); |
254 | dlm_scan_timeout(ls); | 253 | dlm_scan_timeout(ls); |
254 | dlm_scan_waiters(ls); | ||
255 | dlm_unlock_recovery(ls); | 255 | dlm_unlock_recovery(ls); |
256 | } else { | 256 | } else { |
257 | ls->ls_scan_time += HZ; | 257 | ls->ls_scan_time += HZ; |
258 | } | 258 | } |
259 | } else { | 259 | continue; |
260 | schedule_timeout_interruptible(timeout_jiffies); | ||
261 | } | 260 | } |
261 | schedule_timeout_interruptible(dlm_config.ci_scan_secs * HZ); | ||
262 | } | 262 | } |
263 | return 0; | 263 | return 0; |
264 | } | 264 | } |