This is the main ludia_funcs git repository.
Revision | 46536e8eacd637046ad0dff70396758ccf536712 (tree) |
---|---|
Zeit | 2020-02-26 18:39:41 |
Autor | Fujii Masao <fujii@post...> |
Commiter | Fujii Masao |
Support terse logging in enable_debug.
This commit allows us to set enable_debug option to 'terse' as
a setting value. When it's 'terse', the contents dealt in ludia_funcs
internal functions are excluded from the debug messages.
For example, if it's set to 'on', not only the name of function
pgs2norm() but also the target string that the function normalizes
are included in the debug messages. But if it's 'terse', only the
terse information like function name is output.
Previously we set enable_debug to 'on', in order to check
whether recheck is skipped or not in the regression test.
But the order of the contents in the debug messages varied
depending on the block size in PostgreSQL server. Which
would lead to unexpected failure of regression test in PostgreSQL
built with non-default block size. In order to stabilize the result
of this regression test, this patch make the test use debug level
'terse'.
Author: Torikoshi Atsushi
Reviewed-by: Fujii Masao
Discussion: https://osdn.net/projects/ludiafuncs/lists/archive/hackers/2020-February/000046.html
@@ -1066,30 +1066,39 @@ EXPLAIN (costs off) SELECT replace(col1, E'\t', '*') FROM text_tbl | ||
1066 | 1066 | Index Cond: (pgs2norm(col1) ~~ '% %'::text) |
1067 | 1067 | (6 rows) |
1068 | 1068 | |
1069 | --- Test whether recheck is skipped expectedly when keyword length is 1 or 2 | |
1070 | -SET ludia_funcs.enable_debug TO on; | |
1069 | +-- Test whether recheck is skipped expectedly when keyword length is 1 or 2. | |
1070 | +-- We can judge that recheck is skipped successfully if the debug messages | |
1071 | +-- indicating the calls to pgs2norm() and pgs2malloc() are logged only once | |
1072 | +-- respectively. So this test must run with enable_debug enabled. | |
1073 | +-- Note that enable_debug must be set to 'terse' in order to stabilize the | |
1074 | +-- result of this regression test. Otherwise, i.e., when enable_debug is set to | |
1075 | +-- 'on', the contents dealt in function pgs2malloc() and pgs2norm() are logged, | |
1076 | +-- and the order of those debug messages varies depending on the block size | |
1077 | +-- in PostgreSQL server. Those detailed information are not necessary to | |
1078 | +-- judge whether the recheck is skipped or not. | |
1079 | +SET ludia_funcs.enable_debug TO terse; | |
1071 | 1080 | SELECT col1 FROM text_tbl |
1072 | 1081 | WHERE pgs2norm(col1) LIKE likequery(pgs2norm('東京都')) ORDER BY col1; |
1073 | -LOG: pgs2malloc(): buflen 2048, needed 22, maxlen 4194304 | |
1074 | -LOG: pgs2norm(): complete (set result cache): 東京都 | |
1075 | -LOG: pgs2malloc(): buflen 2048, needed 46, maxlen 4194304 | |
1076 | -LOG: pgs2norm(): complete (set result cache): 東京都山田太郎 | |
1077 | -LOG: pgs2malloc(): buflen 2048, needed 22, maxlen 4194304 | |
1078 | -LOG: pgs2norm(): complete (set result cache): 東京都 | |
1079 | -LOG: pgs2malloc(): buflen 2048, needed 48, maxlen 4194304 | |
1080 | -LOG: pgs2norm(): complete (set result cache): 東京都 山田太郎 | |
1081 | -LOG: pgs2malloc(): buflen 2048, needed 48, maxlen 4194304 | |
1082 | -LOG: pgs2norm(): complete (set result cache): 東京都山田 太郎 | |
1083 | -LOG: pgs2malloc(): buflen 2048, needed 50, maxlen 4194304 | |
1084 | -LOG: pgs2norm(): complete (set result cache): 東京都 山田 太郎 | |
1085 | -LOG: pgs2malloc(): buflen 2048, needed 47, maxlen 4194304 | |
1086 | -LOG: pgs2norm(): complete (set result cache): 東京都 山田太郎 | |
1087 | -LOG: pgs2malloc(): buflen 2048, needed 50, maxlen 4194304 | |
1088 | -LOG: pgs2norm(): complete (set result cache): 東京都山田 太郎 | |
1089 | -LOG: pgs2malloc(): buflen 2048, needed 50, maxlen 4194304 | |
1090 | -LOG: pgs2norm(): complete (set result cache): 東京都 山田太郎 | |
1091 | -LOG: pgs2malloc(): buflen 2048, needed 34, maxlen 4194304 | |
1092 | -LOG: pgs2norm(): complete (set result cache): 東京と京都 | |
1082 | +LOG: pgs2malloc() | |
1083 | +LOG: pgs2norm(): complete | |
1084 | +LOG: pgs2malloc() | |
1085 | +LOG: pgs2norm(): complete | |
1086 | +LOG: pgs2malloc() | |
1087 | +LOG: pgs2norm(): complete | |
1088 | +LOG: pgs2malloc() | |
1089 | +LOG: pgs2norm(): complete | |
1090 | +LOG: pgs2malloc() | |
1091 | +LOG: pgs2norm(): complete | |
1092 | +LOG: pgs2malloc() | |
1093 | +LOG: pgs2norm(): complete | |
1094 | +LOG: pgs2malloc() | |
1095 | +LOG: pgs2norm(): complete | |
1096 | +LOG: pgs2malloc() | |
1097 | +LOG: pgs2norm(): complete | |
1098 | +LOG: pgs2malloc() | |
1099 | +LOG: pgs2norm(): complete | |
1100 | +LOG: pgs2malloc() | |
1101 | +LOG: pgs2norm(): complete | |
1093 | 1102 | col1 |
1094 | 1103 | ------------------ |
1095 | 1104 | 東京都 |
@@ -1104,8 +1113,8 @@ LOG: pgs2norm(): complete (set result cache): 東京と京都 | ||
1104 | 1113 | |
1105 | 1114 | SELECT col1 FROM text_tbl |
1106 | 1115 | WHERE pgs2norm(col1) LIKE likequery(pgs2norm('京都')) ORDER BY col1; |
1107 | -LOG: pgs2malloc(): buflen 2048, needed 16, maxlen 4194304 | |
1108 | -LOG: pgs2norm(): complete (set result cache): 京都 | |
1116 | +LOG: pgs2malloc() | |
1117 | +LOG: pgs2norm(): complete | |
1109 | 1118 | col1 |
1110 | 1119 | ------------------ |
1111 | 1120 | 東京と京都 |
@@ -1121,8 +1130,8 @@ LOG: pgs2norm(): complete (set result cache): 京都 | ||
1121 | 1130 | |
1122 | 1131 | SELECT col1 FROM text_tbl |
1123 | 1132 | WHERE pgs2norm(col1) LIKE likequery(pgs2norm('京')) ORDER BY col1; |
1124 | -LOG: pgs2malloc(): buflen 2048, needed 10, maxlen 4194304 | |
1125 | -LOG: pgs2norm(): complete (set result cache): 京 | |
1133 | +LOG: pgs2malloc() | |
1134 | +LOG: pgs2norm(): complete | |
1126 | 1135 | col1 |
1127 | 1136 | ------------------ |
1128 | 1137 | 東京と京都 |
@@ -1138,16 +1147,16 @@ LOG: pgs2norm(): complete (set result cache): 京 | ||
1138 | 1147 | |
1139 | 1148 | SELECT pgs2snippet1(1, 50, 1, '*', '*', 0, '東', col1) FROM text_tbl |
1140 | 1149 | WHERE pgs2norm(col2) LIKE likequery(pgs2norm('東')) ORDER BY col1; |
1141 | -LOG: pgs2malloc(): buflen 2048, needed 10, maxlen 4194304 | |
1142 | -LOG: pgs2norm(): complete (set result cache): 東 | |
1143 | -LOG: GetSennaQuery(): quick exit: 東 | |
1144 | -LOG: GetSennaQuery(): quick exit: 東 | |
1145 | -LOG: GetSennaQuery(): quick exit: 東 | |
1146 | -LOG: GetSennaQuery(): quick exit: 東 | |
1147 | -LOG: GetSennaQuery(): quick exit: 東 | |
1148 | -LOG: GetSennaQuery(): quick exit: 東 | |
1149 | -LOG: GetSennaQuery(): quick exit: 東 | |
1150 | -LOG: GetSennaQuery(): quick exit: 東 | |
1150 | +LOG: pgs2malloc() | |
1151 | +LOG: pgs2norm(): complete | |
1152 | +LOG: GetSennaQuery(): quick exit | |
1153 | +LOG: GetSennaQuery(): quick exit | |
1154 | +LOG: GetSennaQuery(): quick exit | |
1155 | +LOG: GetSennaQuery(): quick exit | |
1156 | +LOG: GetSennaQuery(): quick exit | |
1157 | +LOG: GetSennaQuery(): quick exit | |
1158 | +LOG: GetSennaQuery(): quick exit | |
1159 | +LOG: GetSennaQuery(): quick exit | |
1151 | 1160 | pgs2snippet1 |
1152 | 1161 | -------------------------- |
1153 | 1162 | *東*京と京都 |
@@ -1164,10 +1173,10 @@ LOG: GetSennaQuery(): quick exit: 東 | ||
1164 | 1173 | SELECT col1 FROM text_tbl |
1165 | 1174 | WHERE pgs2norm(col1) LIKE likequery(pgs2norm('山')) |
1166 | 1175 | AND pgs2norm(col1) LIKE likequery(pgs2norm('京')); |
1167 | -LOG: pgs2malloc(): buflen 2048, needed 10, maxlen 4194304 | |
1168 | -LOG: pgs2norm(): complete (set result cache): 山 | |
1169 | -LOG: pgs2malloc(): buflen 2048, needed 10, maxlen 4194304 | |
1170 | -LOG: pgs2norm(): complete (set result cache): 京 | |
1176 | +LOG: pgs2malloc() | |
1177 | +LOG: pgs2norm(): complete | |
1178 | +LOG: pgs2malloc() | |
1179 | +LOG: pgs2norm(): complete | |
1171 | 1180 | col1 |
1172 | 1181 | ------------------ |
1173 | 1182 | 東京都山田太郎 |
@@ -1182,10 +1191,10 @@ LOG: pgs2norm(): complete (set result cache): 京 | ||
1182 | 1191 | SELECT col1 FROM text_tbl |
1183 | 1192 | WHERE pgs2norm(col1) LIKE likequery(pgs2norm('山田')) |
1184 | 1193 | AND pgs2norm(col1) LIKE likequery(pgs2norm('京都')); |
1185 | -LOG: pgs2malloc(): buflen 2048, needed 16, maxlen 4194304 | |
1186 | -LOG: pgs2norm(): complete (set result cache): 山田 | |
1187 | -LOG: pgs2malloc(): buflen 2048, needed 16, maxlen 4194304 | |
1188 | -LOG: pgs2norm(): complete (set result cache): 京都 | |
1194 | +LOG: pgs2malloc() | |
1195 | +LOG: pgs2norm(): complete | |
1196 | +LOG: pgs2malloc() | |
1197 | +LOG: pgs2norm(): complete | |
1189 | 1198 | col1 |
1190 | 1199 | ------------------ |
1191 | 1200 | 東京都山田太郎 |
@@ -1200,31 +1209,31 @@ LOG: pgs2norm(): complete (set result cache): 京都 | ||
1200 | 1209 | SELECT col1 FROM text_tbl |
1201 | 1210 | WHERE pgs2norm(col1) LIKE likequery(pgs2norm('東京都')) |
1202 | 1211 | AND pgs2norm(col1) LIKE likequery(pgs2norm('太')); |
1203 | -LOG: pgs2malloc(): buflen 2048, needed 22, maxlen 4194304 | |
1204 | -LOG: pgs2norm(): complete (set result cache): 東京都 | |
1205 | -LOG: pgs2malloc(): buflen 2048, needed 10, maxlen 4194304 | |
1206 | -LOG: pgs2norm(): complete (set result cache): 太 | |
1207 | -LOG: pgs2malloc(): buflen 2048, needed 46, maxlen 4194304 | |
1208 | -LOG: pgs2norm(): complete (set result cache): 東京都山田太郎 | |
1209 | -LOG: pgs2norm(): quick exit: 東京都山田太郎 | |
1210 | -LOG: pgs2malloc(): buflen 2048, needed 48, maxlen 4194304 | |
1211 | -LOG: pgs2norm(): complete (set result cache): 東京都 山田太郎 | |
1212 | -LOG: pgs2norm(): quick exit: 東京都 山田太郎 | |
1213 | -LOG: pgs2malloc(): buflen 2048, needed 48, maxlen 4194304 | |
1214 | -LOG: pgs2norm(): complete (set result cache): 東京都山田 太郎 | |
1215 | -LOG: pgs2norm(): quick exit: 東京都山田 太郎 | |
1216 | -LOG: pgs2malloc(): buflen 2048, needed 50, maxlen 4194304 | |
1217 | -LOG: pgs2norm(): complete (set result cache): 東京都 山田 太郎 | |
1218 | -LOG: pgs2norm(): quick exit: 東京都 山田 太郎 | |
1219 | -LOG: pgs2malloc(): buflen 2048, needed 47, maxlen 4194304 | |
1220 | -LOG: pgs2norm(): complete (set result cache): 東京都 山田太郎 | |
1221 | -LOG: pgs2norm(): quick exit: 東京都 山田太郎 | |
1222 | -LOG: pgs2malloc(): buflen 2048, needed 50, maxlen 4194304 | |
1223 | -LOG: pgs2norm(): complete (set result cache): 東京都山田 太郎 | |
1224 | -LOG: pgs2norm(): quick exit: 東京都山田 太郎 | |
1225 | -LOG: pgs2malloc(): buflen 2048, needed 50, maxlen 4194304 | |
1226 | -LOG: pgs2norm(): complete (set result cache): 東京都 山田太郎 | |
1227 | -LOG: pgs2norm(): quick exit: 東京都 山田太郎 | |
1212 | +LOG: pgs2malloc() | |
1213 | +LOG: pgs2norm(): complete | |
1214 | +LOG: pgs2malloc() | |
1215 | +LOG: pgs2norm(): complete | |
1216 | +LOG: pgs2malloc() | |
1217 | +LOG: pgs2norm(): complete | |
1218 | +LOG: pgs2norm(): quick exit | |
1219 | +LOG: pgs2malloc() | |
1220 | +LOG: pgs2norm(): complete | |
1221 | +LOG: pgs2norm(): quick exit | |
1222 | +LOG: pgs2malloc() | |
1223 | +LOG: pgs2norm(): complete | |
1224 | +LOG: pgs2norm(): quick exit | |
1225 | +LOG: pgs2malloc() | |
1226 | +LOG: pgs2norm(): complete | |
1227 | +LOG: pgs2norm(): quick exit | |
1228 | +LOG: pgs2malloc() | |
1229 | +LOG: pgs2norm(): complete | |
1230 | +LOG: pgs2norm(): quick exit | |
1231 | +LOG: pgs2malloc() | |
1232 | +LOG: pgs2norm(): complete | |
1233 | +LOG: pgs2norm(): quick exit | |
1234 | +LOG: pgs2malloc() | |
1235 | +LOG: pgs2norm(): complete | |
1236 | +LOG: pgs2norm(): quick exit | |
1228 | 1237 | col1 |
1229 | 1238 | ------------------ |
1230 | 1239 | 東京都山田太郎 |
@@ -40,8 +40,31 @@ PG_MODULE_MAGIC; | ||
40 | 40 | |
41 | 41 | /* GUC variables */ |
42 | 42 | #ifdef PGS2_DEBUG |
43 | -static bool pgs2_enable_debug = false; | |
44 | -#endif | |
43 | +typedef enum pgs2_enable_debug_type | |
44 | +{ | |
45 | + PGS2_ENABLE_DEBUG_OFF, /* logs no debug log */ | |
46 | + PGS2_ENABLE_DEBUG_TERSE, /* logs tersely, e.g., just names of | |
47 | + functions */ | |
48 | + PGS2_ENABLE_DEBUG_ON /* logs detailed infomation */ | |
49 | +} pgs2_enable_debug_type; | |
50 | + | |
51 | +/* We accept all the likely variants of "on" and "off" */ | |
52 | +static const struct config_enum_entry pgs2_enable_debug_options[] = { | |
53 | + {"off", PGS2_ENABLE_DEBUG_OFF, false}, | |
54 | + {"terse", PGS2_ENABLE_DEBUG_TERSE, false}, | |
55 | + {"on", PGS2_ENABLE_DEBUG_ON, false}, | |
56 | + {"true", PGS2_ENABLE_DEBUG_ON, true}, | |
57 | + {"false", PGS2_ENABLE_DEBUG_OFF, true}, | |
58 | + {"yes", PGS2_ENABLE_DEBUG_ON, true}, | |
59 | + {"no", PGS2_ENABLE_DEBUG_OFF, true}, | |
60 | + {"1", PGS2_ENABLE_DEBUG_ON, true}, | |
61 | + {"0", PGS2_ENABLE_DEBUG_OFF, true}, | |
62 | + {NULL, 0, false} | |
63 | +}; | |
64 | + | |
65 | +static int pgs2_enable_debug = PGS2_ENABLE_DEBUG_OFF; | |
66 | +#endif /* PGS2_DEBUG */ | |
67 | + | |
45 | 68 | static char *pgs2_last_update = NULL; |
46 | 69 | static int norm_cache_limit = -1; |
47 | 70 | static bool escape_snippet_keyword = false; |
@@ -132,11 +155,12 @@ _PG_init(void) | ||
132 | 155 | |
133 | 156 | #ifdef PGS2_DEBUG |
134 | 157 | /* Define custom GUC variable for debugging */ |
135 | - DefineCustomBoolVariable("ludia_funcs.enable_debug", | |
158 | + DefineCustomEnumVariable("ludia_funcs.enable_debug", | |
136 | 159 | "Emit ludia_funcs debugging output.", |
137 | 160 | NULL, |
138 | 161 | &pgs2_enable_debug, |
139 | - false, | |
162 | + PGS2_ENABLE_DEBUG_OFF, | |
163 | + pgs2_enable_debug_options, | |
140 | 164 | PGC_USERSET, |
141 | 165 | 0, |
142 | 166 | NULL, |
@@ -626,13 +650,15 @@ EscapeSnippetKeyword(char **s, size_t *slen) | ||
626 | 650 | *slen = ep - *s; |
627 | 651 | |
628 | 652 | #ifdef PGS2_DEBUG |
629 | - if (pgs2_enable_debug) | |
653 | + if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_ON) | |
630 | 654 | { |
631 | 655 | char *tmp = pnstrdup(*s, *slen); |
632 | 656 | |
633 | 657 | elog(LOG, "escaped snippet keyword: %s", tmp); |
634 | 658 | pfree(tmp); |
635 | 659 | } |
660 | + else if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_TERSE) | |
661 | + elog(LOG, "escaped snippet keyword"); | |
636 | 662 | #endif |
637 | 663 | |
638 | 664 | return true; |
@@ -662,13 +688,15 @@ GetSennaQuery(char *str, size_t len) | ||
662 | 688 | escape_snippet_keyword == guc_cache) |
663 | 689 | { |
664 | 690 | #ifdef PGS2_DEBUG |
665 | - if (pgs2_enable_debug) | |
691 | + if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_ON) | |
666 | 692 | { |
667 | 693 | char *tmp = pnstrdup(str, len); |
668 | 694 | |
669 | 695 | elog(LOG, "GetSennaQuery(): quick exit: %s", tmp); |
670 | 696 | pfree(tmp); |
671 | 697 | } |
698 | + else if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_TERSE) | |
699 | + elog(LOG, "GetSennaQuery(): quick exit"); | |
672 | 700 | #endif |
673 | 701 | return query_cache; |
674 | 702 | } |
@@ -809,9 +837,11 @@ static inline void | ||
809 | 837 | pgs2malloc(void **buf, long *buflen, long needed, long maxlen) |
810 | 838 | { |
811 | 839 | #ifdef PGS2_DEBUG |
812 | - if (pgs2_enable_debug) | |
840 | + if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_ON) | |
813 | 841 | elog(LOG, "pgs2malloc(): buflen %ld, needed %ld, maxlen %ld", |
814 | 842 | *buflen, needed, maxlen); |
843 | + else if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_TERSE) | |
844 | + elog(LOG, "pgs2malloc()"); | |
815 | 845 | #endif |
816 | 846 | |
817 | 847 | if (*buf != NULL && *buflen >= needed && (*buflen <= maxlen || maxlen == 0)) |
@@ -907,13 +937,15 @@ pgs2norm(PG_FUNCTION_ARGS) | ||
907 | 937 | strncmp(norm_cache, s, slen) == 0) |
908 | 938 | { |
909 | 939 | #ifdef PGS2_DEBUG |
910 | - if (pgs2_enable_debug) | |
940 | + if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_ON) | |
911 | 941 | { |
912 | 942 | char *tmp = text_to_cstring(str); |
913 | 943 | |
914 | 944 | elog(LOG, "pgs2norm(): quick exit: %s", tmp); |
915 | 945 | pfree(tmp); |
916 | 946 | } |
947 | + else if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_TERSE) | |
948 | + elog(LOG, "pgs2norm(): quick exit"); | |
917 | 949 | #endif |
918 | 950 | |
919 | 951 | result = (text *) palloc(norm_reslen); |
@@ -987,7 +1019,7 @@ retry: | ||
987 | 1019 | } |
988 | 1020 | |
989 | 1021 | #ifdef PGS2_DEBUG |
990 | - if (pgs2_enable_debug) | |
1022 | + if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_ON) | |
991 | 1023 | { |
992 | 1024 | char *tmp = text_to_cstring(str); |
993 | 1025 |
@@ -995,6 +1027,8 @@ retry: | ||
995 | 1027 | (norm_cache == NULL) ? "unset" : "set", tmp); |
996 | 1028 | pfree(tmp); |
997 | 1029 | } |
1030 | + else if (pgs2_enable_debug == PGS2_ENABLE_DEBUG_TERSE) | |
1031 | + elog(LOG, "pgs2norm(): complete"); | |
998 | 1032 | #endif |
999 | 1033 | |
1000 | 1034 | PG_RETURN_TEXT_P(result); |
@@ -384,8 +384,17 @@ EXPLAIN (costs off) SELECT replace(col1, E'\t', '*') FROM text_tbl | ||
384 | 384 | WHERE pgs2norm(col1) LIKE likequery(pgs2norm(' ')) |
385 | 385 | ORDER BY col1; |
386 | 386 | |
387 | --- Test whether recheck is skipped expectedly when keyword length is 1 or 2 | |
388 | -SET ludia_funcs.enable_debug TO on; | |
387 | +-- Test whether recheck is skipped expectedly when keyword length is 1 or 2. | |
388 | +-- We can judge that recheck is skipped successfully if the debug messages | |
389 | +-- indicating the calls to pgs2norm() and pgs2malloc() are logged only once | |
390 | +-- respectively. So this test must run with enable_debug enabled. | |
391 | +-- Note that enable_debug must be set to 'terse' in order to stabilize the | |
392 | +-- result of this regression test. Otherwise, i.e., when enable_debug is set to | |
393 | +-- 'on', the contents dealt in function pgs2malloc() and pgs2norm() are logged, | |
394 | +-- and the order of those debug messages varies depending on the block size | |
395 | +-- in PostgreSQL server. Those detailed information are not necessary to | |
396 | +-- judge whether the recheck is skipped or not. | |
397 | +SET ludia_funcs.enable_debug TO terse; | |
389 | 398 | SELECT col1 FROM text_tbl |
390 | 399 | WHERE pgs2norm(col1) LIKE likequery(pgs2norm('東京都')) ORDER BY col1; |
391 | 400 | SELECT col1 FROM text_tbl |