如何像在其他 DBMS 中一样在 Tarantool 中获取查询时间
How to get query timing in Tarantool like in other DBMS
在MySQL/PostgreSQL/Oracle/MSSQL中，每个执行的查询总是有持续时间“查询在 0.23 毫秒内完成”或“已用 0.001 秒”，或者至少在显示“EXPLAIN”或“EXPLAIN ANALYZE”时显示时间。如何在 tarantool 客户端中执行此操作？ (tarantoolctl connect 3301)
例如 EXPLAIN QUERY PLAN 根本不显示时间：
box.execute "explain query plan \nWITH sc AS ( -- shown count\n\tSELECT \"ref_id\"\n\t\t, \"view_count\"\n\tFROM \"userlistings\"\n\tWHERE \"user_id\" = 'af07e444-44f3-4116-833e-90af7f24ffa0'\n), msc AS (\n\tSELECT GREATEST(1,MAX(\"view_count\")) \"max_view\"\n\tFROM sc\n)\n, \nopq AS ( \n\tSELECT \"cat_id\"\n\t\t, \"click_interest\" -- SPEC-Q\n\t\t, \"purchase_interest\" -- SPEC-P\n\t\t, \"message_interest\" -- SPEC-O\n\tFROM \"usercats\"\n\tWHERE \"user_id\" = 'af07e444-44f3-4116-833e-90af7f24ffa0'\n), mopq AS (\n\tSELECT GREATEST(1,MAX(\"click_interest\")) \"max_click\"\n\t\t, GREATEST(1,MAX(\"purchase_interest\")) \"max_purchase\"\n\t\t, GREATEST(1,MAX(\"message_interest\")) \"max_inquiry\"\n\tFROM opq\n)\nSELECT \"initial_cache\" \n+ (IFNULL(msc.\"max_view\",1) - IFNULL(sc.\"view_count\",0)) / IFNULL(msc.\"max_view\",1) * 100.0 * 5.28000020980835/100.010002136\n+ ((180-abs(\"lat\" - -5.796658992767334))/360.0 + (360-abs(\"long\" - 106.49927520751953))/720.0) * 100.0 * 22.280000686645508/100.010002136\n+ IFNULL(\"message_interest\",0) / IFNULL(mopq.\"max_inquiry\",1) * 100.0 * 0/100.010002136\n+ IFNULL(\"purchase_interest\",0) / IFNULL(mopq.\"max_purchase\",1) * 100.0 * 5.28000020980835/100.010002136\n+ IFNULL(\"click_interest\",0) / IFNULL(mopq.\"max_click\",1) * 100.0 * 0/100.010002136, *\nFROM \"listings\"\n\nLEFT JOIN sc\n\tON \"listings\".\"ref_id\" = sc.\"ref_id\"\nCROSS JOIN msc\n\nLEFT JOIN opq\n\tON \"listings\".\"categories\" = opq.\"cat_id\"\nCROSS JOIN mopq\n\nWHERE \"ref_type\" = 1\nORDER BY 1 DESC LIMIT 5 OFFSET 0"
---
- metadata:
- name: selectid
type: integer
- name: order
type: integer
- name: from
type: integer
- name: detail
type: text
rows:
- [1, 0, 0, 'SEARCH TABLE userlistings USING PRIMARY KEY (user_id=?) (~10 rows)']
- [2, 0, 0, 'SEARCH TABLE userlistings USING PRIMARY KEY (user_id=?) (~10 rows)']
- [3, 0, 0, 'SEARCH TABLE usercats USING PRIMARY KEY (user_id=?) (~10 rows)']
- [4, 0, 0, 'SEARCH TABLE usercats USING PRIMARY KEY (user_id=?) (~10 rows)']
- [0, 0, 0, 'SEARCH TABLE listings USING COVERING INDEX ref_type (ref_type=?) (~10
rows)']
- [0, 1, 1, 'SCAN SUBQUERY 1 (~1 row)']
- [0, 2, 2, 'SCAN SUBQUERY 2 (~1 row)']
- [0, 3, 3, 'SCAN SUBQUERY 3 (~1 row)']
- [0, 4, 4, 'SCAN SUBQUERY 4 (~1 row)']
- [0, 0, 0, 'USE TEMP B-TREE FOR ORDER BY']
...
或 EXPLAIN 也没有显示任何 timing/duration:
box.execute "explain \nWITH sc AS ( -- shown count\n\tSELECT \"ref_id\"\n\t\t, \"view_count\"\n\tFROM \"userlistings\"\n\tWHERE \"user_id\" = 'af07e444-44f3-4116-833e-90af7f24ffa0'\n), msc AS (\n\tSELECT GREATEST(1,MAX(\"view_count\")) \"max_view\"\n\tFROM sc\n)\n, \nopq AS ( \n\tSELECT \"cat_id\"\n\t\t, \"click_interest\" -- SPEC-Q\n\t\t, \"purchase_interest\" -- SPEC-P\n\t\t, \"message_interest\" -- SPEC-O\n\tFROM \"usercats\"\n\tWHERE \"user_id\" = 'af07e444-44f3-4116-833e-90af7f24ffa0'\n), mopq AS (\n\tSELECT GREATEST(1,MAX(\"click_interest\")) \"max_click\"\n\t\t, GREATEST(1,MAX(\"purchase_interest\")) \"max_purchase\"\n\t\t, GREATEST(1,MAX(\"message_interest\")) \"max_inquiry\"\n\tFROM opq\n)\nSELECT \"initial_cache\" \n+ (IFNULL(msc.\"max_view\",1) - IFNULL(sc.\"view_count\",0)) / IFNULL(msc.\"max_view\",1) * 100.0 * 5.28000020980835/100.010002136\n+ ((180-abs(\"lat\" - -5.796658992767334))/360.0 + (360-abs(\"long\" - 106.49927520751953))/720.0) * 100.0 * 22.280000686645508/100.010002136\n+ IFNULL(\"message_interest\",0) / IFNULL(mopq.\"max_inquiry\",1) * 100.0 * 0/100.010002136\n+ IFNULL(\"purchase_interest\",0) / IFNULL(mopq.\"max_purchase\",1) * 100.0 * 5.28000020980835/100.010002136\n+ IFNULL(\"click_interest\",0) / IFNULL(mopq.\"max_click\",1) * 100.0 * 0/100.010002136, *\nFROM \"listings\"\n\nLEFT JOIN sc\n\tON \"listings\".\"ref_id\" = sc.\"ref_id\"\nCROSS JOIN msc\n\nLEFT JOIN opq\n\tON \"listings\".\"categories\" = opq.\"cat_id\"\nCROSS JOIN mopq\n\nWHERE \"ref_type\" = 1\nORDER BY 1 DESC LIMIT 5 OFFSET 0"
---
- metadata:
- name: addr
type: integer
- name: opcode
type: text
- name: p1
type: integer
- name: p2
type: integer
- name: p3
type: integer
- name: p4
type: text
- name: p5
type: text
- name: comment
type: text
rows:
- [0, 'Init', 0, 324, 0, '', '00', null]
- [1, 'Integer', 18, 1, 0, '', '00', null]
- [2, 'Once', 0, 18, 0, '', '00', null]
- [3, 'OpenTEphemeral', 2, 3, 0, 'k(2,B,B)', '00', null]
- [4, 'IteratorOpen', 1, 0, 2, '', '00', null]
- [5, 'IteratorOpen', 11, 0, 0, 'space<name=userlistings>', '02', null]
- [6, 'String8', 0, 3, 0, 'af07e444-44f3-4116-833e-90af7f24ffa0', '00', null]
- [7, 'ApplyType', 3, 1, 0, "\x02", '00', null]
- [8, 'SeekGE', 11, 18, 3, '1', '00', null]
- [9, 'IdxGT', 11, 18, 3, '1', '00', null]
- [10, 'Column', 11, 1, 4, '', '00', null]
- [11, 'Column', 11, 2, 5, '', '00', null]
- [12, 'MakeRecord', 4, 2, 6, '', '01', null]
- [13, 'NextIdEphemeral', 2, 10, 0, '', '00', null]
- [14, 'Copy', 4, 8, 1, '', '00', null]
- [15, 'MakeRecord', 8, 3, 7, '', '01', null]
- [16, 'IdxInsert', 7, 2, 0, '', '00', null]
- [17, 'Next', 11, 9, 0, '', '00', null]
- [18, 'Return', 1, 0, 0, '', '00', null]
- [19, 'Integer', 42, 11, 0, '', '00', null]
- [20, 'Once', 0, 42, 0, '', '00', null]
- [21, 'OpenTEphemeral', 12, 2, 0, 'k(1,B)', '00', null]
- [22, 'IteratorOpen', 2, 0, 12, '', '00', null]
- [23, 'Null', 0, 13, 14, '', '00', null]
- [24, 'IteratorOpen', 12, 0, 0, 'space<name=userlistings>', '02', null]
- [25, 'String8', 0, 15, 0, 'af07e444-44f3-4116-833e-90af7f24ffa0', '00', null]
- [26, 'ApplyType', 15, 1, 0, "\x02", '00', null]
- [27, 'SeekGE', 12, 33, 15, '1', '00', null]
- [28, 'IdxGT', 12, 33, 15, '1', '00', null]
- [29, 'Column', 12, 2, 16, '', '00', null]
- [30, 'CollSeq', 0, 0, 0, '(binary)', '00', null]
- [31, 'AggStep0', 0, 16, 13, 'MAX(1)', '01', null]
- [32, 'Next', 12, 28, 0, '', '00', null]
- [33, 'AggFinal', 13, 1, 0, 'MAX(1)', '00', null]
- [34, 'Copy', 13, 19, 0, '', '00', null]
- [35, 'CollSeq', 0, 0, 0, '({type = binary})', '00', null]
- [36, 'BuiltinFunction0', 1, 18, 17, 'GREATEST(-1)', '02', null]
- [37, 'MakeRecord', 17, 1, 16, '', '01', null]
- [38, 'NextIdEphemeral', 12, 22, 0, '', '00', null]
- [39, 'Copy', 17, 21, 0, '', '00', null]
- [40, 'MakeRecord', 21, 2, 20, '', '01', null]
- [41, 'IdxInsert', 20, 12, 0, '', '00', null]
- [42, 'Return', 11, 0, 0, '', '00', null]
- [43, 'Integer', 62, 23, 0, '', '00', null]
- [44, 'Once', 0, 62, 0, '', '00', null]
- [45, 'OpenTEphemeral', 24, 5, 0, 'k(4,B,B,B,B)', '00', null]
- [46, 'IteratorOpen', 3, 0, 24, '', '00', null]
- [47, 'IteratorOpen', 13, 0, 0, 'space<name=usercats>', '02', null]
- [48, 'String8', 0, 25, 0, 'af07e444-44f3-4116-833e-90af7f24ffa0', '00', null]
- [49, 'ApplyType', 25, 1, 0, "\x02", '00', null]
- [50, 'SeekGE', 13, 62, 25, '1', '00', null]
- [51, 'IdxGT', 13, 62, 25, '1', '00', null]
- [52, 'Column', 13, 1, 26, '', '00', null]
- [53, 'Column', 13, 5, 27, '', '00', null]
- [54, 'Column', 13, 4, 28, '', '00', null]
- [55, 'Column', 13, 3, 29, '', '00', null]
- [56, 'MakeRecord', 26, 4, 30, '', '01', null]
- [57, 'NextIdEphemeral', 24, 36, 0, '', '00', null]
- [58, 'Copy', 26, 32, 3, '', '00', null]
- [59, 'MakeRecord', 32, 5, 31, '', '01', null]
- [60, 'IdxInsert', 31, 24, 0, '', '00', null]
- [61, 'Next', 13, 51, 0, '', '00', null]
- [62, 'Return', 23, 0, 0, '', '00', null]
- [63, 'Integer', 100, 37, 0, '', '00', null]
- [64, 'Once', 0, 100, 0, '', '00', null]
- [65, 'OpenTEphemeral', 38, 4, 0, 'k(3,B,B,B)', '00', null]
- [66, 'IteratorOpen', 4, 0, 38, '', '00', null]
- [67, 'Null', 0, 39, 44, '', '00', null]
- [68, 'IteratorOpen', 14, 0, 0, 'space<name=usercats>', '02', null]
- [69, 'String8', 0, 45, 0, 'af07e444-44f3-4116-833e-90af7f24ffa0', '00', null]
- [70, 'ApplyType', 45, 1, 0, "\x02", '00', null]
- [71, 'SeekGE', 14, 83, 45, '1', '00', null]
- [72, 'IdxGT', 14, 83, 45, '1', '00', null]
- [73, 'Column', 14, 5, 46, '', '00', null]
- [74, 'CollSeq', 0, 0, 0, '(binary)', '00', null]
- [75, 'AggStep0', 0, 46, 39, 'MAX(1)', '01', null]
- [76, 'Column', 14, 4, 46, '', '00', null]
- [77, 'CollSeq', 0, 0, 0, '(binary)', '00', null]
- [78, 'AggStep0', 0, 46, 40, 'MAX(1)', '01', null]
- [79, 'Column', 14, 3, 46, '', '00', null]
- [80, 'CollSeq', 0, 0, 0, '(binary)', '00', null]
- [81, 'AggStep0', 0, 46, 41, 'MAX(1)', '01', null]
- [82, 'Next', 14, 72, 0, '', '00', null]
- [83, 'AggFinal', 39, 1, 0, 'MAX(1)', '00', null]
- [84, 'AggFinal', 40, 1, 0, 'MAX(1)', '00', null]
- [85, 'AggFinal', 41, 1, 0, 'MAX(1)', '00', null]
- [86, 'Copy', 39, 51, 0, '', '00', null]
- [87, 'CollSeq', 0, 0, 0, '({type = binary})', '00', null]
- [88, 'BuiltinFunction0', 1, 50, 47, 'GREATEST(-1)', '02', null]
- [89, 'Copy', 40, 53, 0, '', '00', null]
- [90, 'CollSeq', 0, 0, 0, '({type = binary})', '00', null]
- [91, 'BuiltinFunction0', 1, 52, 48, 'GREATEST(-1)', '02', null]
- [92, 'Copy', 41, 55, 0, '', '00', null]
- [93, 'CollSeq', 0, 0, 0, '({type = binary})', '00', null]
- [94, 'BuiltinFunction0', 1, 54, 49, 'GREATEST(-1)', '02', null]
- [95, 'MakeRecord', 47, 3, 46, '', '01', null]
- [96, 'NextIdEphemeral', 38, 60, 0, '', '00', null]
- [97, 'Copy', 47, 57, 2, '', '00', null]
- [98, 'MakeRecord', 57, 4, 56, '', '01', null]
- [99, 'IdxInsert', 56, 38, 0, '', '00', null]
- [100, 'Return', 37, 0, 0, '', '00', null]
- [101, 'OpenTEphemeral', 61, 52, 0, 'k(1,-B)', '00', null]
- [102, 'IteratorOpen', 15, 0, 61, '', '00', null]
- [103, 'Integer', 5, 62, 0, '', '00', null]
- [104, 'MustBeInt', 62, 107, 0, '', '00', null]
- [105, 'Integer', 0, 63, 0, '', '00', null]
- [106, 'Ge', 63, 109, 62, '', '00', null]
- [107, 'SetDiag', 159, 0, 0, 'Failed to execute SQL statement: Only positive integers
are allowed in the LIMIT clause', '00', null]
- [108, 'Halt', -1, 0, 0, '', '00', null]
- [109, 'Eq', 63, 323, 62, '', '00', null]
- [110, 'Integer', 0, 64, 0, '', '00', null]
- [111, 'MustBeInt', 64, 114, 0, '', '00', null]
- [112, 'Integer', 0, 63, 0, '', '00', null]
- [113, 'Ge', 63, 116, 64, '', '00', null]
- [114, 'SetDiag', 159, 0, 0, 'Failed to execute SQL statement: Only positive integers
are allowed in the OFFSET clause', '00', null]
- [115, 'Halt', -1, 0, 0, '', '00', null]
- [116, 'OffsetLimit', 62, 65, 64, '', '00', null]
- [117, 'IteratorOpen', 16, 1, 0, 'space<name=listings>', '02', null]
- [118, 'Integer', 1, 66, 0, '', '00', null]
- [119, 'IsNull', 66, 121, 0, '', '00', null]
- [120, 'MustBeInt', 66, 268, 0, '', '00', null]
- [121, 'SeekGE', 16, 268, 66, '1', '00', null]
- [122, 'IdxGT', 16, 268, 66, '1', '00', null]
- [123, 'Integer', 0, 67, 0, '', '00', null]
- [124, 'Rewind', 1, 264, 0, '', '00', null]
- [125, 'Column', 16, 0, 63, '', '00', null]
- [126, 'Column', 1, 0, 68, '', '00', null]
- [127, 'Ne', 68, 263, 63, '({type = binary})', '18', null]
- [128, 'Integer', 1, 67, 0, '', '00', null]
- [129, 'Rewind', 2, 263, 0, '', '00', null]
- [130, 'Integer', 0, 69, 0, '', '00', null]
- [131, 'Rewind', 3, 259, 0, '', '00', null]
- [132, 'Column', 16, 22, 68, '', '00', null]
- [133, 'Column', 3, 0, 63, '', '00', null]
- [134, 'Ne', 63, 258, 68, '({type = binary})', '18', null]
- [135, 'Integer', 1, 69, 0, '', '00', null]
- [136, 'Rewind', 4, 258, 0, '', '00', null]
- [137, 'Column', 16, 0, 72, '', '00', null]
- [138, 'Column', 16, 1, 73, '', '00', null]
- [139, 'Column', 16, 2, 74, '', '00', null]
- [140, 'Column', 16, 3, 75, '', '00', null]
- [141, 'Column', 16, 4, 76, '', '00', null]
- [142, 'Column', 16, 5, 77, '', '00', null]
- [143, 'Column', 16, 6, 78, '', '00', null]
- [144, 'Column', 16, 7, 79, '', '00', null]
- [145, 'Column', 16, 8, 80, '', '00', null]
- [146, 'Column', 16, 9, 81, '', '00', null]
- [147, 'Column', 16, 10, 82, '', '00', null]
- [148, 'Column', 16, 11, 83, '', '00', null]
- [149, 'Column', 16, 12, 84, '', '00', null]
- [150, 'Column', 16, 13, 85, '', '00', null]
- [151, 'Column', 16, 14, 86, '', '00', null]
- [152, 'Column', 16, 15, 87, '', '00', null]
- [153, 'Column', 16, 16, 88, '', '00', null]
- [154, 'Column', 16, 17, 89, '', '00', null]
- [155, 'Column', 16, 18, 90, '', '00', null]
- [156, 'Column', 16, 19, 91, '', '00', null]
- [157, 'Column', 16, 20, 92, '', '00', null]
- [158, 'Column', 16, 21, 93, '', '00', null]
- [159, 'Column', 16, 22, 94, '', '00', null]
- [160, 'Column', 16, 23, 95, '', '00', null]
- [161, 'Column', 16, 24, 96, '', '00', null]
- [162, 'Column', 16, 25, 97, '', '00', null]
- [163, 'Column', 16, 26, 98, '', '00', null]
- [164, 'Column', 16, 27, 99, '', '00', null]
- [165, 'Column', 16, 28, 100, '', '00', null]
- [166, 'Column', 16, 29, 101, '', '00', null]
- [167, 'Column', 16, 30, 102, '', '00', null]
- [168, 'Column', 16, 31, 103, '', '00', null]
- [169, 'Column', 16, 32, 104, '', '00', null]
- [170, 'Column', 16, 33, 105, '', '00', null]
- [171, 'Column', 16, 34, 106, '', '00', null]
- [172, 'Column', 16, 35, 107, '', '00', null]
- [173, 'Column', 16, 36, 108, '', '00', null]
- [174, 'Column', 16, 37, 109, '', '00', null]
- [175, 'Column', 16, 38, 110, '', '00', null]
- [176, 'Column', 16, 39, 111, '', '00', null]
- [177, 'Column', 1, 0, 112, '', '00', null]
- [178, 'Column', 1, 1, 113, '', '00', null]
- [179, 'Column', 2, 0, 114, '', '00', null]
- [180, 'Column', 3, 0, 115, '', '00', null]
- [181, 'Column', 3, 1, 116, '', '00', null]
- [182, 'Column', 3, 2, 117, '', '00', null]
- [183, 'Column', 3, 3, 118, '', '00', null]
- [184, 'Column', 4, 0, 119, '', '00', null]
- [185, 'Column', 4, 1, 120, '', '00', null]
- [186, 'Column', 4, 2, 121, '', '00', null]
- [187, 'Column', 16, 35, 126, '', '00', null]
- [188, 'SCopy', 114, 132, 0, '', '00', null]
- [189, 'NotNull', 132, 191, 0, '', '00', null]
- [190, 'Integer', 1, 132, 0, '', '00', null]
- [191, 'SCopy', 113, 133, 0, '', '00', null]
- [192, 'NotNull', 133, 194, 0, '', '00', null]
- [193, 'Integer', 0, 133, 0, '', '00', null]
- [194, 'Subtract', 133, 132, 131, '', '00', null]
- [195, 'SCopy', 114, 133, 0, '', '00', null]
- [196, 'NotNull', 133, 198, 0, '', '00', null]
- [197, 'Integer', 1, 133, 0, '', '00', null]
- [198, 'Divide', 133, 131, 130, '', '00', null]
- [199, 'Multiply', 134, 130, 129, '', '00', null]
- [200, 'Multiply', 135, 129, 128, '', '00', null]
- [201, 'Divide', 136, 128, 127, '', '00', null]
- [202, 'Add', 127, 126, 125, '', '00', null]
- [203, 'Column', 16, 7, 139, '', '00', null]
- [204, 'Subtract', 140, 139, 138, '', '00', null]
- [205, 'BuiltinFunction0', 0, 138, 132, 'ABS(1)', '01', null]
- [206, 'Subtract', 132, 137, 131, '', '00', null]
- [207, 'Divide', 141, 131, 133, '', '00', null]
- [208, 'Column', 16, 8, 143, '', '00', null]
- [209, 'Subtract', 144, 143, 139, '', '00', null]
- [210, 'BuiltinFunction0', 0, 139, 138, 'ABS(1)', '01', null]
- [211, 'Subtract', 138, 142, 132, '', '00', null]
- [212, 'Divide', 145, 132, 131, '', '00', null]
- [213, 'Add', 131, 133, 130, '', '00', null]
- [214, 'Multiply', 134, 130, 129, '', '00', null]
- [215, 'Multiply', 146, 129, 128, '', '00', null]
- [216, 'Divide', 136, 128, 127, '', '00', null]
- [217, 'Add', 127, 125, 124, '', '00', null]
- [218, 'SCopy', 118, 132, 0, '', '00', null]
- [219, 'NotNull', 132, 221, 0, '', '00', null]
- [220, 'Integer', 0, 132, 0, '', '00', null]
- [221, 'SCopy', 121, 138, 0, '', '00', null]
- [222, 'NotNull', 138, 224, 0, '', '00', null]
- [223, 'Integer', 1, 138, 0, '', '00', null]
- [224, 'Divide', 138, 132, 133, '', '00', null]
- [225, 'Multiply', 134, 133, 131, '', '00', null]
- [226, 'Multiply', 147, 131, 130, '', '00', null]
- [227, 'Divide', 136, 130, 129, '', '00', null]
- [228, 'Add', 129, 124, 68, '', '00', null]
- [229, 'SCopy', 117, 138, 0, '', '00', null]
- [230, 'NotNull', 138, 232, 0, '', '00', null]
- [231, 'Integer', 0, 138, 0, '', '00', null]
- [232, 'SCopy', 120, 132, 0, '', '00', null]
- [233, 'NotNull', 132, 235, 0, '', '00', null]
- [234, 'Integer', 1, 132, 0, '', '00', null]
- [235, 'Divide', 132, 138, 133, '', '00', null]
- [236, 'Multiply', 134, 133, 131, '', '00', null]
- [237, 'Multiply', 135, 131, 130, '', '00', null]
- [238, 'Divide', 136, 130, 124, '', '00', null]
- [239, 'Add', 124, 68, 63, '', '00', null]
- [240, 'SCopy', 116, 132, 0, '', '00', null]
- [241, 'NotNull', 132, 243, 0, '', '00', null]
- [242, 'Integer', 0, 132, 0, '', '00', null]
- [243, 'SCopy', 119, 138, 0, '', '00', null]
- [244, 'NotNull', 138, 246, 0, '', '00', null]
- [245, 'Integer', 1, 138, 0, '', '00', null]
- [246, 'Divide', 138, 132, 133, '', '00', null]
- [247, 'Multiply', 134, 133, 131, '', '00', null]
- [248, 'Multiply', 147, 131, 130, '', '00', null]
- [249, 'Divide', 136, 130, 68, '', '00', null]
- [250, 'Add', 68, 63, 70, '', '00', null]
- [251, 'Sequence', 15, 71, 0, '', '00', null]
- [252, 'MakeRecord', 70, 52, 123, '', '00', null]
- [253, 'IdxInsert', 123, 61, 0, '', '00', null]
- [254, 'IfNotZero', 65, 257, 0, '', '00', null]
- [255, 'Rewind', 15, 256, 0, '', '00', null]
- [256, 'Delete', 15, 0, 0, '', '00', null]
- [257, 'Next', 4, 137, 0, '', '01', null]
- [258, 'Next', 3, 132, 0, '', '01', null]
- [259, 'IfPos', 69, 262, 0, '', '00', null]
- [260, 'NullRow', 3, 0, 0, '', '00', null]
- [261, 'Goto', 0, 135, 0, '', '00', null]
- [262, 'Next', 2, 130, 0, '', '01', null]
- [263, 'Next', 1, 125, 0, '', '01', null]
- [264, 'IfPos', 67, 267, 0, '', '00', null]
- [265, 'NullRow', 1, 0, 0, '', '00', null]
- [266, 'Goto', 0, 128, 0, '', '00', null]
- [267, 'Next', 16, 122, 1, '', '00', null]
- [268, 'Last', 15, 323, 0, '', '00', null]
- [269, 'IfPos', 64, 322, 1, '', '00', null]
- [270, 'Column', 15, 0, 72, '', '00', null]
- [271, 'Column', 15, 2, 73, '', '00', null]
- [272, 'Column', 15, 3, 74, '', '00', null]
- [273, 'Column', 15, 4, 75, '', '00', null]
- [274, 'Column', 15, 5, 76, '', '00', null]
- [275, 'Column', 15, 6, 77, '', '00', null]
- [276, 'Column', 15, 7, 78, '', '00', null]
- [277, 'Column', 15, 8, 79, '', '00', null]
- [278, 'Column', 15, 9, 80, '', '00', null]
- [279, 'Column', 15, 10, 81, '', '00', null]
- [280, 'Column', 15, 11, 82, '', '00', null]
- [281, 'Column', 15, 12, 83, '', '00', null]
- [282, 'Column', 15, 13, 84, '', '00', null]
- [283, 'Column', 15, 14, 85, '', '00', null]
- [284, 'Column', 15, 15, 86, '', '00', null]
- [285, 'Column', 15, 16, 87, '', '00', null]
- [286, 'Column', 15, 17, 88, '', '00', null]
- [287, 'Column', 15, 18, 89, '', '00', null]
- [288, 'Column', 15, 19, 90, '', '00', null]
- [289, 'Column', 15, 20, 91, '', '00', null]
- [290, 'Column', 15, 21, 92, '', '00', null]
- [291, 'Column', 15, 22, 93, '', '00', null]
- [292, 'Column', 15, 23, 94, '', '00', null]
- [293, 'Column', 15, 24, 95, '', '00', null]
- [294, 'Column', 15, 25, 96, '', '00', null]
- [295, 'Column', 15, 26, 97, '', '00', null]
- [296, 'Column', 15, 27, 98, '', '00', null]
- [297, 'Column', 15, 28, 99, '', '00', null]
- [298, 'Column', 15, 29, 100, '', '00', null]
- [299, 'Column', 15, 30, 101, '', '00', null]
- [300, 'Column', 15, 31, 102, '', '00', null]
- [301, 'Column', 15, 32, 103, '', '00', null]
- [302, 'Column', 15, 33, 104, '', '00', null]
- [303, 'Column', 15, 34, 105, '', '00', null]
- [304, 'Column', 15, 35, 106, '', '00', null]
- [305, 'Column', 15, 36, 107, '', '00', null]
- [306, 'Column', 15, 37, 108, '', '00', null]
- [307, 'Column', 15, 38, 109, '', '00', null]
- [308, 'Column', 15, 39, 110, '', '00', null]
- [309, 'Column', 15, 40, 111, '', '00', null]
- [310, 'Column', 15, 41, 112, '', '00', null]
- [311, 'Column', 15, 42, 113, '', '00', null]
- [312, 'Column', 15, 43, 114, '', '00', null]
- [313, 'Column', 15, 44, 115, '', '00', null]
- [314, 'Column', 15, 45, 116, '', '00', null]
- [315, 'Column', 15, 46, 117, '', '00', null]
- [316, 'Column', 15, 47, 118, '', '00', null]
- [317, 'Column', 15, 48, 119, '', '00', null]
- [318, 'Column', 15, 49, 120, '', '00', null]
- [319, 'Column', 15, 50, 121, '', '00', null]
- [320, 'Column', 15, 51, 122, '', '00', null]
- [321, 'ResultRow', 72, 51, 0, '', '00', null]
- [322, 'Prev', 15, 269, 0, '', '00', null]
- [323, 'Halt', 0, 0, 0, '', '00', null]
- [324, 'Integer', 1, 18, 0, '', '00', null]
- [325, 'Integer', 1, 50, 0, '', '00', null]
- [326, 'Integer', 1, 52, 0, '', '00', null]
- [327, 'Integer', 1, 54, 0, '', '00', null]
- [328, 'Real', 0, 134, 0, '100', '00', null]
- [329, 'Real', 0, 135, 0, '5.28000020980835', '00', null]
- [330, 'Real', 0, 136, 0, '100.010002136', '00', null]
- [331, 'Integer', 180, 137, 0, '', '00', null]
- [332, 'Real', 0, 140, 0, '-5.796658992767334', '00', null]
- [333, 'Real', 0, 141, 0, '360', '00', null]
- [334, 'Integer', 360, 142, 0, '', '00', null]
- [335, 'Real', 0, 144, 0, '106.4992752075195', '00', null]
- [336, 'Real', 0, 145, 0, '720', '00', null]
- [337, 'Real', 0, 146, 0, '22.28000068664551', '00', null]
- [338, 'Integer', 0, 147, 0, '', '00', null]
- [339, 'Goto', 0, 1, 0, '', '00', null]
...
原始查询（以前使用像 (SELECT "max_click" FROM mopq) 这样的子查询，但与 CROSS JOIN:
相比，它提供更长的 explain
WITH sc AS ( -- shown count
SELECT "ref_id"
, "view_count"
FROM "userlistings"
WHERE "user_id" = 'af07e444-44f3-4116-833e-90af7f24ffa0'
), msc AS (
SELECT GREATEST(1,MAX("view_count")) "max_view"
FROM sc
)
,
opq AS (
SELECT "cat_id"
, "click_interest" -- SPEC-Q
, "purchase_interest" -- SPEC-P
, "message_interest" -- SPEC-O
FROM "usercats"
WHERE "user_id" = 'af07e444-44f3-4116-833e-90af7f24ffa0'
), mopq AS (
SELECT GREATEST(1,MAX("click_interest")) "max_click"
, GREATEST(1,MAX("purchase_interest")) "max_purchase"
, GREATEST(1,MAX("message_interest")) "max_inquiry"
FROM opq
)
SELECT "initial_cache"
+ (IFNULL(msc."max_view",1) - IFNULL(sc."view_count",0)) / IFNULL(msc."max_view",1) * 100.0 * 5.28000020980835/100.010002136
+ ((180-abs("lat" - -5.796658992767334))/360.0 + (360-abs("long" - 106.49927520751953))/720.0) * 100.0 * 22.280000686645508/100.010002136
+ IFNULL("message_interest",0) / IFNULL(mopq."max_inquiry",1) * 100.0 * 0/100.010002136
+ IFNULL("purchase_interest",0) / IFNULL(mopq."max_purchase",1) * 100.0 * 5.28000020980835/100.010002136
+ IFNULL("click_interest",0) / IFNULL(mopq."max_click",1) * 100.0 * 0/100.010002136, *
FROM "listings"
LEFT JOIN sc
ON "listings"."ref_id" = sc."ref_id"
CROSS JOIN msc
LEFT JOIN opq
ON "listings"."categories" = opq."cat_id"
CROSS JOIN mopq
WHERE "ref_type" = 1
ORDER BY 1 DESC LIMIT 5 OFFSET 0
这个查询的持续时间有点奇怪（在 go 程序中测量，但每次我需要更改查询时部署都会花费很多时间）：
ref_type = 1 (3538 rows) 587ms
ref_type = 5 ( 886 rows) 142ms
ref_type = 3 ( 104 rows) 9ms
ref_type = 6 (1608 rows) 276ms
没有本地（即 SQL 类）方法来衡量查询执行时间。但是，您可以将查询包装在跟踪时间的 Lua 函数中（使用 os Lua 模块）。示例取自 SQL reference:
function main_function()
local string_value, t, sql_statement
for i = 1,1000000, 1 do
string_value = string_function()
sql_statement = "INSERT INTO tester VALUES (" .. i .. ",'" .. string_value .. "')"
box.execute(sql_statement)
end
end
start_time = os.clock()
main_function()
end_time = os.clock()
'insert done in ' .. end_time - start_time .. ' seconds'
欢迎在 github 上打开功能请求：https://github.com/tarantool/tarantool/issues/new
同意这是不幸和不便的，我们计划在相当短的时间内让它变得更加方便。
作为今天的变通办法，我建议您启用 VDBE_PROFILE 并重新编译 Tarantool，这将生成带有 运行 注释的时间信息 VDBE 查询执行到 [=12] 的日志=] 文件，您可以在其中看到计时和计数器。
diff --git a/src/box/CMakeLists.txt b/src/box/CMakeLists.txt
index 999ac4749..0126f5af3 100644
--- a/src/box/CMakeLists.txt
+++ b/src/box/CMakeLists.txt
@@ -222,6 +222,7 @@ if(CMAKE_BUILD_TYPE STREQUAL "Debug")
add_definitions(-DSQL_DEBUG=1)
endif()
add_definitions(-DSQL_TEST=1)
+add_definitions(-DVDBE_PROFILE=1)
set(EXT_SRC_DIR ${CMAKE_SOURCE_DIR}/extra)
set(EXT_BIN_DIR ${CMAKE_BINARY_DIR}/extra)
根据 NikitaRock 的回答修改，创建一个像这样的辅助函数 T:
> function T(sql_statement)
start_time = os.clock()
res = box.execute(sql_statement)
end_time = os.clock()
return box.tuple.new(res, 'Query done in ' .. string.format("%.2f",(end_time - start_time)*1000) .. ' ms')
end
> T 'SELECT COUNT(*) FROM "listings" WHERE "ref_type" = 6;'
---
- [{'metadata': [{'name': 'COLUMN_1', 'type': 'integer'}], 'rows': [[1608]]}, 'Query
done in 0.49 ms']
...
在MySQL/PostgreSQL/Oracle/MSSQL中，每个执行的查询总是有持续时间“查询在 0.23 毫秒内完成”或“已用 0.001 秒”，或者至少在显示“EXPLAIN”或“EXPLAIN ANALYZE”时显示时间。如何在 tarantool 客户端中执行此操作？ (tarantoolctl connect 3301)
例如 EXPLAIN QUERY PLAN 根本不显示时间：
box.execute "explain query plan \nWITH sc AS ( -- shown count\n\tSELECT \"ref_id\"\n\t\t, \"view_count\"\n\tFROM \"userlistings\"\n\tWHERE \"user_id\" = 'af07e444-44f3-4116-833e-90af7f24ffa0'\n), msc AS (\n\tSELECT GREATEST(1,MAX(\"view_count\")) \"max_view\"\n\tFROM sc\n)\n, \nopq AS ( \n\tSELECT \"cat_id\"\n\t\t, \"click_interest\" -- SPEC-Q\n\t\t, \"purchase_interest\" -- SPEC-P\n\t\t, \"message_interest\" -- SPEC-O\n\tFROM \"usercats\"\n\tWHERE \"user_id\" = 'af07e444-44f3-4116-833e-90af7f24ffa0'\n), mopq AS (\n\tSELECT GREATEST(1,MAX(\"click_interest\")) \"max_click\"\n\t\t, GREATEST(1,MAX(\"purchase_interest\")) \"max_purchase\"\n\t\t, GREATEST(1,MAX(\"message_interest\")) \"max_inquiry\"\n\tFROM opq\n)\nSELECT \"initial_cache\" \n+ (IFNULL(msc.\"max_view\",1) - IFNULL(sc.\"view_count\",0)) / IFNULL(msc.\"max_view\",1) * 100.0 * 5.28000020980835/100.010002136\n+ ((180-abs(\"lat\" - -5.796658992767334))/360.0 + (360-abs(\"long\" - 106.49927520751953))/720.0) * 100.0 * 22.280000686645508/100.010002136\n+ IFNULL(\"message_interest\",0) / IFNULL(mopq.\"max_inquiry\",1) * 100.0 * 0/100.010002136\n+ IFNULL(\"purchase_interest\",0) / IFNULL(mopq.\"max_purchase\",1) * 100.0 * 5.28000020980835/100.010002136\n+ IFNULL(\"click_interest\",0) / IFNULL(mopq.\"max_click\",1) * 100.0 * 0/100.010002136, *\nFROM \"listings\"\n\nLEFT JOIN sc\n\tON \"listings\".\"ref_id\" = sc.\"ref_id\"\nCROSS JOIN msc\n\nLEFT JOIN opq\n\tON \"listings\".\"categories\" = opq.\"cat_id\"\nCROSS JOIN mopq\n\nWHERE \"ref_type\" = 1\nORDER BY 1 DESC LIMIT 5 OFFSET 0"
---
- metadata:
- name: selectid
type: integer
- name: order
type: integer
- name: from
type: integer
- name: detail
type: text
rows:
- [1, 0, 0, 'SEARCH TABLE userlistings USING PRIMARY KEY (user_id=?) (~10 rows)']
- [2, 0, 0, 'SEARCH TABLE userlistings USING PRIMARY KEY (user_id=?) (~10 rows)']
- [3, 0, 0, 'SEARCH TABLE usercats USING PRIMARY KEY (user_id=?) (~10 rows)']
- [4, 0, 0, 'SEARCH TABLE usercats USING PRIMARY KEY (user_id=?) (~10 rows)']
- [0, 0, 0, 'SEARCH TABLE listings USING COVERING INDEX ref_type (ref_type=?) (~10
rows)']
- [0, 1, 1, 'SCAN SUBQUERY 1 (~1 row)']
- [0, 2, 2, 'SCAN SUBQUERY 2 (~1 row)']
- [0, 3, 3, 'SCAN SUBQUERY 3 (~1 row)']
- [0, 4, 4, 'SCAN SUBQUERY 4 (~1 row)']
- [0, 0, 0, 'USE TEMP B-TREE FOR ORDER BY']
...
或 EXPLAIN 也没有显示任何 timing/duration:
box.execute "explain \nWITH sc AS ( -- shown count\n\tSELECT \"ref_id\"\n\t\t, \"view_count\"\n\tFROM \"userlistings\"\n\tWHERE \"user_id\" = 'af07e444-44f3-4116-833e-90af7f24ffa0'\n), msc AS (\n\tSELECT GREATEST(1,MAX(\"view_count\")) \"max_view\"\n\tFROM sc\n)\n, \nopq AS ( \n\tSELECT \"cat_id\"\n\t\t, \"click_interest\" -- SPEC-Q\n\t\t, \"purchase_interest\" -- SPEC-P\n\t\t, \"message_interest\" -- SPEC-O\n\tFROM \"usercats\"\n\tWHERE \"user_id\" = 'af07e444-44f3-4116-833e-90af7f24ffa0'\n), mopq AS (\n\tSELECT GREATEST(1,MAX(\"click_interest\")) \"max_click\"\n\t\t, GREATEST(1,MAX(\"purchase_interest\")) \"max_purchase\"\n\t\t, GREATEST(1,MAX(\"message_interest\")) \"max_inquiry\"\n\tFROM opq\n)\nSELECT \"initial_cache\" \n+ (IFNULL(msc.\"max_view\",1) - IFNULL(sc.\"view_count\",0)) / IFNULL(msc.\"max_view\",1) * 100.0 * 5.28000020980835/100.010002136\n+ ((180-abs(\"lat\" - -5.796658992767334))/360.0 + (360-abs(\"long\" - 106.49927520751953))/720.0) * 100.0 * 22.280000686645508/100.010002136\n+ IFNULL(\"message_interest\",0) / IFNULL(mopq.\"max_inquiry\",1) * 100.0 * 0/100.010002136\n+ IFNULL(\"purchase_interest\",0) / IFNULL(mopq.\"max_purchase\",1) * 100.0 * 5.28000020980835/100.010002136\n+ IFNULL(\"click_interest\",0) / IFNULL(mopq.\"max_click\",1) * 100.0 * 0/100.010002136, *\nFROM \"listings\"\n\nLEFT JOIN sc\n\tON \"listings\".\"ref_id\" = sc.\"ref_id\"\nCROSS JOIN msc\n\nLEFT JOIN opq\n\tON \"listings\".\"categories\" = opq.\"cat_id\"\nCROSS JOIN mopq\n\nWHERE \"ref_type\" = 1\nORDER BY 1 DESC LIMIT 5 OFFSET 0"
---
- metadata:
- name: addr
type: integer
- name: opcode
type: text
- name: p1
type: integer
- name: p2
type: integer
- name: p3
type: integer
- name: p4
type: text
- name: p5
type: text
- name: comment
type: text
rows:
- [0, 'Init', 0, 324, 0, '', '00', null]
- [1, 'Integer', 18, 1, 0, '', '00', null]
- [2, 'Once', 0, 18, 0, '', '00', null]
- [3, 'OpenTEphemeral', 2, 3, 0, 'k(2,B,B)', '00', null]
- [4, 'IteratorOpen', 1, 0, 2, '', '00', null]
- [5, 'IteratorOpen', 11, 0, 0, 'space<name=userlistings>', '02', null]
- [6, 'String8', 0, 3, 0, 'af07e444-44f3-4116-833e-90af7f24ffa0', '00', null]
- [7, 'ApplyType', 3, 1, 0, "\x02", '00', null]
- [8, 'SeekGE', 11, 18, 3, '1', '00', null]
- [9, 'IdxGT', 11, 18, 3, '1', '00', null]
- [10, 'Column', 11, 1, 4, '', '00', null]
- [11, 'Column', 11, 2, 5, '', '00', null]
- [12, 'MakeRecord', 4, 2, 6, '', '01', null]
- [13, 'NextIdEphemeral', 2, 10, 0, '', '00', null]
- [14, 'Copy', 4, 8, 1, '', '00', null]
- [15, 'MakeRecord', 8, 3, 7, '', '01', null]
- [16, 'IdxInsert', 7, 2, 0, '', '00', null]
- [17, 'Next', 11, 9, 0, '', '00', null]
- [18, 'Return', 1, 0, 0, '', '00', null]
- [19, 'Integer', 42, 11, 0, '', '00', null]
- [20, 'Once', 0, 42, 0, '', '00', null]
- [21, 'OpenTEphemeral', 12, 2, 0, 'k(1,B)', '00', null]
- [22, 'IteratorOpen', 2, 0, 12, '', '00', null]
- [23, 'Null', 0, 13, 14, '', '00', null]
- [24, 'IteratorOpen', 12, 0, 0, 'space<name=userlistings>', '02', null]
- [25, 'String8', 0, 15, 0, 'af07e444-44f3-4116-833e-90af7f24ffa0', '00', null]
- [26, 'ApplyType', 15, 1, 0, "\x02", '00', null]
- [27, 'SeekGE', 12, 33, 15, '1', '00', null]
- [28, 'IdxGT', 12, 33, 15, '1', '00', null]
- [29, 'Column', 12, 2, 16, '', '00', null]
- [30, 'CollSeq', 0, 0, 0, '(binary)', '00', null]
- [31, 'AggStep0', 0, 16, 13, 'MAX(1)', '01', null]
- [32, 'Next', 12, 28, 0, '', '00', null]
- [33, 'AggFinal', 13, 1, 0, 'MAX(1)', '00', null]
- [34, 'Copy', 13, 19, 0, '', '00', null]
- [35, 'CollSeq', 0, 0, 0, '({type = binary})', '00', null]
- [36, 'BuiltinFunction0', 1, 18, 17, 'GREATEST(-1)', '02', null]
- [37, 'MakeRecord', 17, 1, 16, '', '01', null]
- [38, 'NextIdEphemeral', 12, 22, 0, '', '00', null]
- [39, 'Copy', 17, 21, 0, '', '00', null]
- [40, 'MakeRecord', 21, 2, 20, '', '01', null]
- [41, 'IdxInsert', 20, 12, 0, '', '00', null]
- [42, 'Return', 11, 0, 0, '', '00', null]
- [43, 'Integer', 62, 23, 0, '', '00', null]
- [44, 'Once', 0, 62, 0, '', '00', null]
- [45, 'OpenTEphemeral', 24, 5, 0, 'k(4,B,B,B,B)', '00', null]
- [46, 'IteratorOpen', 3, 0, 24, '', '00', null]
- [47, 'IteratorOpen', 13, 0, 0, 'space<name=usercats>', '02', null]
- [48, 'String8', 0, 25, 0, 'af07e444-44f3-4116-833e-90af7f24ffa0', '00', null]
- [49, 'ApplyType', 25, 1, 0, "\x02", '00', null]
- [50, 'SeekGE', 13, 62, 25, '1', '00', null]
- [51, 'IdxGT', 13, 62, 25, '1', '00', null]
- [52, 'Column', 13, 1, 26, '', '00', null]
- [53, 'Column', 13, 5, 27, '', '00', null]
- [54, 'Column', 13, 4, 28, '', '00', null]
- [55, 'Column', 13, 3, 29, '', '00', null]
- [56, 'MakeRecord', 26, 4, 30, '', '01', null]
- [57, 'NextIdEphemeral', 24, 36, 0, '', '00', null]
- [58, 'Copy', 26, 32, 3, '', '00', null]
- [59, 'MakeRecord', 32, 5, 31, '', '01', null]
- [60, 'IdxInsert', 31, 24, 0, '', '00', null]
- [61, 'Next', 13, 51, 0, '', '00', null]
- [62, 'Return', 23, 0, 0, '', '00', null]
- [63, 'Integer', 100, 37, 0, '', '00', null]
- [64, 'Once', 0, 100, 0, '', '00', null]
- [65, 'OpenTEphemeral', 38, 4, 0, 'k(3,B,B,B)', '00', null]
- [66, 'IteratorOpen', 4, 0, 38, '', '00', null]
- [67, 'Null', 0, 39, 44, '', '00', null]
- [68, 'IteratorOpen', 14, 0, 0, 'space<name=usercats>', '02', null]
- [69, 'String8', 0, 45, 0, 'af07e444-44f3-4116-833e-90af7f24ffa0', '00', null]
- [70, 'ApplyType', 45, 1, 0, "\x02", '00', null]
- [71, 'SeekGE', 14, 83, 45, '1', '00', null]
- [72, 'IdxGT', 14, 83, 45, '1', '00', null]
- [73, 'Column', 14, 5, 46, '', '00', null]
- [74, 'CollSeq', 0, 0, 0, '(binary)', '00', null]
- [75, 'AggStep0', 0, 46, 39, 'MAX(1)', '01', null]
- [76, 'Column', 14, 4, 46, '', '00', null]
- [77, 'CollSeq', 0, 0, 0, '(binary)', '00', null]
- [78, 'AggStep0', 0, 46, 40, 'MAX(1)', '01', null]
- [79, 'Column', 14, 3, 46, '', '00', null]
- [80, 'CollSeq', 0, 0, 0, '(binary)', '00', null]
- [81, 'AggStep0', 0, 46, 41, 'MAX(1)', '01', null]
- [82, 'Next', 14, 72, 0, '', '00', null]
- [83, 'AggFinal', 39, 1, 0, 'MAX(1)', '00', null]
- [84, 'AggFinal', 40, 1, 0, 'MAX(1)', '00', null]
- [85, 'AggFinal', 41, 1, 0, 'MAX(1)', '00', null]
- [86, 'Copy', 39, 51, 0, '', '00', null]
- [87, 'CollSeq', 0, 0, 0, '({type = binary})', '00', null]
- [88, 'BuiltinFunction0', 1, 50, 47, 'GREATEST(-1)', '02', null]
- [89, 'Copy', 40, 53, 0, '', '00', null]
- [90, 'CollSeq', 0, 0, 0, '({type = binary})', '00', null]
- [91, 'BuiltinFunction0', 1, 52, 48, 'GREATEST(-1)', '02', null]
- [92, 'Copy', 41, 55, 0, '', '00', null]
- [93, 'CollSeq', 0, 0, 0, '({type = binary})', '00', null]
- [94, 'BuiltinFunction0', 1, 54, 49, 'GREATEST(-1)', '02', null]
- [95, 'MakeRecord', 47, 3, 46, '', '01', null]
- [96, 'NextIdEphemeral', 38, 60, 0, '', '00', null]
- [97, 'Copy', 47, 57, 2, '', '00', null]
- [98, 'MakeRecord', 57, 4, 56, '', '01', null]
- [99, 'IdxInsert', 56, 38, 0, '', '00', null]
- [100, 'Return', 37, 0, 0, '', '00', null]
- [101, 'OpenTEphemeral', 61, 52, 0, 'k(1,-B)', '00', null]
- [102, 'IteratorOpen', 15, 0, 61, '', '00', null]
- [103, 'Integer', 5, 62, 0, '', '00', null]
- [104, 'MustBeInt', 62, 107, 0, '', '00', null]
- [105, 'Integer', 0, 63, 0, '', '00', null]
- [106, 'Ge', 63, 109, 62, '', '00', null]
- [107, 'SetDiag', 159, 0, 0, 'Failed to execute SQL statement: Only positive integers
are allowed in the LIMIT clause', '00', null]
- [108, 'Halt', -1, 0, 0, '', '00', null]
- [109, 'Eq', 63, 323, 62, '', '00', null]
- [110, 'Integer', 0, 64, 0, '', '00', null]
- [111, 'MustBeInt', 64, 114, 0, '', '00', null]
- [112, 'Integer', 0, 63, 0, '', '00', null]
- [113, 'Ge', 63, 116, 64, '', '00', null]
- [114, 'SetDiag', 159, 0, 0, 'Failed to execute SQL statement: Only positive integers
are allowed in the OFFSET clause', '00', null]
- [115, 'Halt', -1, 0, 0, '', '00', null]
- [116, 'OffsetLimit', 62, 65, 64, '', '00', null]
- [117, 'IteratorOpen', 16, 1, 0, 'space<name=listings>', '02', null]
- [118, 'Integer', 1, 66, 0, '', '00', null]
- [119, 'IsNull', 66, 121, 0, '', '00', null]
- [120, 'MustBeInt', 66, 268, 0, '', '00', null]
- [121, 'SeekGE', 16, 268, 66, '1', '00', null]
- [122, 'IdxGT', 16, 268, 66, '1', '00', null]
- [123, 'Integer', 0, 67, 0, '', '00', null]
- [124, 'Rewind', 1, 264, 0, '', '00', null]
- [125, 'Column', 16, 0, 63, '', '00', null]
- [126, 'Column', 1, 0, 68, '', '00', null]
- [127, 'Ne', 68, 263, 63, '({type = binary})', '18', null]
- [128, 'Integer', 1, 67, 0, '', '00', null]
- [129, 'Rewind', 2, 263, 0, '', '00', null]
- [130, 'Integer', 0, 69, 0, '', '00', null]
- [131, 'Rewind', 3, 259, 0, '', '00', null]
- [132, 'Column', 16, 22, 68, '', '00', null]
- [133, 'Column', 3, 0, 63, '', '00', null]
- [134, 'Ne', 63, 258, 68, '({type = binary})', '18', null]
- [135, 'Integer', 1, 69, 0, '', '00', null]
- [136, 'Rewind', 4, 258, 0, '', '00', null]
- [137, 'Column', 16, 0, 72, '', '00', null]
- [138, 'Column', 16, 1, 73, '', '00', null]
- [139, 'Column', 16, 2, 74, '', '00', null]
- [140, 'Column', 16, 3, 75, '', '00', null]
- [141, 'Column', 16, 4, 76, '', '00', null]
- [142, 'Column', 16, 5, 77, '', '00', null]
- [143, 'Column', 16, 6, 78, '', '00', null]
- [144, 'Column', 16, 7, 79, '', '00', null]
- [145, 'Column', 16, 8, 80, '', '00', null]
- [146, 'Column', 16, 9, 81, '', '00', null]
- [147, 'Column', 16, 10, 82, '', '00', null]
- [148, 'Column', 16, 11, 83, '', '00', null]
- [149, 'Column', 16, 12, 84, '', '00', null]
- [150, 'Column', 16, 13, 85, '', '00', null]
- [151, 'Column', 16, 14, 86, '', '00', null]
- [152, 'Column', 16, 15, 87, '', '00', null]
- [153, 'Column', 16, 16, 88, '', '00', null]
- [154, 'Column', 16, 17, 89, '', '00', null]
- [155, 'Column', 16, 18, 90, '', '00', null]
- [156, 'Column', 16, 19, 91, '', '00', null]
- [157, 'Column', 16, 20, 92, '', '00', null]
- [158, 'Column', 16, 21, 93, '', '00', null]
- [159, 'Column', 16, 22, 94, '', '00', null]
- [160, 'Column', 16, 23, 95, '', '00', null]
- [161, 'Column', 16, 24, 96, '', '00', null]
- [162, 'Column', 16, 25, 97, '', '00', null]
- [163, 'Column', 16, 26, 98, '', '00', null]
- [164, 'Column', 16, 27, 99, '', '00', null]
- [165, 'Column', 16, 28, 100, '', '00', null]
- [166, 'Column', 16, 29, 101, '', '00', null]
- [167, 'Column', 16, 30, 102, '', '00', null]
- [168, 'Column', 16, 31, 103, '', '00', null]
- [169, 'Column', 16, 32, 104, '', '00', null]
- [170, 'Column', 16, 33, 105, '', '00', null]
- [171, 'Column', 16, 34, 106, '', '00', null]
- [172, 'Column', 16, 35, 107, '', '00', null]
- [173, 'Column', 16, 36, 108, '', '00', null]
- [174, 'Column', 16, 37, 109, '', '00', null]
- [175, 'Column', 16, 38, 110, '', '00', null]
- [176, 'Column', 16, 39, 111, '', '00', null]
- [177, 'Column', 1, 0, 112, '', '00', null]
- [178, 'Column', 1, 1, 113, '', '00', null]
- [179, 'Column', 2, 0, 114, '', '00', null]
- [180, 'Column', 3, 0, 115, '', '00', null]
- [181, 'Column', 3, 1, 116, '', '00', null]
- [182, 'Column', 3, 2, 117, '', '00', null]
- [183, 'Column', 3, 3, 118, '', '00', null]
- [184, 'Column', 4, 0, 119, '', '00', null]
- [185, 'Column', 4, 1, 120, '', '00', null]
- [186, 'Column', 4, 2, 121, '', '00', null]
- [187, 'Column', 16, 35, 126, '', '00', null]
- [188, 'SCopy', 114, 132, 0, '', '00', null]
- [189, 'NotNull', 132, 191, 0, '', '00', null]
- [190, 'Integer', 1, 132, 0, '', '00', null]
- [191, 'SCopy', 113, 133, 0, '', '00', null]
- [192, 'NotNull', 133, 194, 0, '', '00', null]
- [193, 'Integer', 0, 133, 0, '', '00', null]
- [194, 'Subtract', 133, 132, 131, '', '00', null]
- [195, 'SCopy', 114, 133, 0, '', '00', null]
- [196, 'NotNull', 133, 198, 0, '', '00', null]
- [197, 'Integer', 1, 133, 0, '', '00', null]
- [198, 'Divide', 133, 131, 130, '', '00', null]
- [199, 'Multiply', 134, 130, 129, '', '00', null]
- [200, 'Multiply', 135, 129, 128, '', '00', null]
- [201, 'Divide', 136, 128, 127, '', '00', null]
- [202, 'Add', 127, 126, 125, '', '00', null]
- [203, 'Column', 16, 7, 139, '', '00', null]
- [204, 'Subtract', 140, 139, 138, '', '00', null]
- [205, 'BuiltinFunction0', 0, 138, 132, 'ABS(1)', '01', null]
- [206, 'Subtract', 132, 137, 131, '', '00', null]
- [207, 'Divide', 141, 131, 133, '', '00', null]
- [208, 'Column', 16, 8, 143, '', '00', null]
- [209, 'Subtract', 144, 143, 139, '', '00', null]
- [210, 'BuiltinFunction0', 0, 139, 138, 'ABS(1)', '01', null]
- [211, 'Subtract', 138, 142, 132, '', '00', null]
- [212, 'Divide', 145, 132, 131, '', '00', null]
- [213, 'Add', 131, 133, 130, '', '00', null]
- [214, 'Multiply', 134, 130, 129, '', '00', null]
- [215, 'Multiply', 146, 129, 128, '', '00', null]
- [216, 'Divide', 136, 128, 127, '', '00', null]
- [217, 'Add', 127, 125, 124, '', '00', null]
- [218, 'SCopy', 118, 132, 0, '', '00', null]
- [219, 'NotNull', 132, 221, 0, '', '00', null]
- [220, 'Integer', 0, 132, 0, '', '00', null]
- [221, 'SCopy', 121, 138, 0, '', '00', null]
- [222, 'NotNull', 138, 224, 0, '', '00', null]
- [223, 'Integer', 1, 138, 0, '', '00', null]
- [224, 'Divide', 138, 132, 133, '', '00', null]
- [225, 'Multiply', 134, 133, 131, '', '00', null]
- [226, 'Multiply', 147, 131, 130, '', '00', null]
- [227, 'Divide', 136, 130, 129, '', '00', null]
- [228, 'Add', 129, 124, 68, '', '00', null]
- [229, 'SCopy', 117, 138, 0, '', '00', null]
- [230, 'NotNull', 138, 232, 0, '', '00', null]
- [231, 'Integer', 0, 138, 0, '', '00', null]
- [232, 'SCopy', 120, 132, 0, '', '00', null]
- [233, 'NotNull', 132, 235, 0, '', '00', null]
- [234, 'Integer', 1, 132, 0, '', '00', null]
- [235, 'Divide', 132, 138, 133, '', '00', null]
- [236, 'Multiply', 134, 133, 131, '', '00', null]
- [237, 'Multiply', 135, 131, 130, '', '00', null]
- [238, 'Divide', 136, 130, 124, '', '00', null]
- [239, 'Add', 124, 68, 63, '', '00', null]
- [240, 'SCopy', 116, 132, 0, '', '00', null]
- [241, 'NotNull', 132, 243, 0, '', '00', null]
- [242, 'Integer', 0, 132, 0, '', '00', null]
- [243, 'SCopy', 119, 138, 0, '', '00', null]
- [244, 'NotNull', 138, 246, 0, '', '00', null]
- [245, 'Integer', 1, 138, 0, '', '00', null]
- [246, 'Divide', 138, 132, 133, '', '00', null]
- [247, 'Multiply', 134, 133, 131, '', '00', null]
- [248, 'Multiply', 147, 131, 130, '', '00', null]
- [249, 'Divide', 136, 130, 68, '', '00', null]
- [250, 'Add', 68, 63, 70, '', '00', null]
- [251, 'Sequence', 15, 71, 0, '', '00', null]
- [252, 'MakeRecord', 70, 52, 123, '', '00', null]
- [253, 'IdxInsert', 123, 61, 0, '', '00', null]
- [254, 'IfNotZero', 65, 257, 0, '', '00', null]
- [255, 'Rewind', 15, 256, 0, '', '00', null]
- [256, 'Delete', 15, 0, 0, '', '00', null]
- [257, 'Next', 4, 137, 0, '', '01', null]
- [258, 'Next', 3, 132, 0, '', '01', null]
- [259, 'IfPos', 69, 262, 0, '', '00', null]
- [260, 'NullRow', 3, 0, 0, '', '00', null]
- [261, 'Goto', 0, 135, 0, '', '00', null]
- [262, 'Next', 2, 130, 0, '', '01', null]
- [263, 'Next', 1, 125, 0, '', '01', null]
- [264, 'IfPos', 67, 267, 0, '', '00', null]
- [265, 'NullRow', 1, 0, 0, '', '00', null]
- [266, 'Goto', 0, 128, 0, '', '00', null]
- [267, 'Next', 16, 122, 1, '', '00', null]
- [268, 'Last', 15, 323, 0, '', '00', null]
- [269, 'IfPos', 64, 322, 1, '', '00', null]
- [270, 'Column', 15, 0, 72, '', '00', null]
- [271, 'Column', 15, 2, 73, '', '00', null]
- [272, 'Column', 15, 3, 74, '', '00', null]
- [273, 'Column', 15, 4, 75, '', '00', null]
- [274, 'Column', 15, 5, 76, '', '00', null]
- [275, 'Column', 15, 6, 77, '', '00', null]
- [276, 'Column', 15, 7, 78, '', '00', null]
- [277, 'Column', 15, 8, 79, '', '00', null]
- [278, 'Column', 15, 9, 80, '', '00', null]
- [279, 'Column', 15, 10, 81, '', '00', null]
- [280, 'Column', 15, 11, 82, '', '00', null]
- [281, 'Column', 15, 12, 83, '', '00', null]
- [282, 'Column', 15, 13, 84, '', '00', null]
- [283, 'Column', 15, 14, 85, '', '00', null]
- [284, 'Column', 15, 15, 86, '', '00', null]
- [285, 'Column', 15, 16, 87, '', '00', null]
- [286, 'Column', 15, 17, 88, '', '00', null]
- [287, 'Column', 15, 18, 89, '', '00', null]
- [288, 'Column', 15, 19, 90, '', '00', null]
- [289, 'Column', 15, 20, 91, '', '00', null]
- [290, 'Column', 15, 21, 92, '', '00', null]
- [291, 'Column', 15, 22, 93, '', '00', null]
- [292, 'Column', 15, 23, 94, '', '00', null]
- [293, 'Column', 15, 24, 95, '', '00', null]
- [294, 'Column', 15, 25, 96, '', '00', null]
- [295, 'Column', 15, 26, 97, '', '00', null]
- [296, 'Column', 15, 27, 98, '', '00', null]
- [297, 'Column', 15, 28, 99, '', '00', null]
- [298, 'Column', 15, 29, 100, '', '00', null]
- [299, 'Column', 15, 30, 101, '', '00', null]
- [300, 'Column', 15, 31, 102, '', '00', null]
- [301, 'Column', 15, 32, 103, '', '00', null]
- [302, 'Column', 15, 33, 104, '', '00', null]
- [303, 'Column', 15, 34, 105, '', '00', null]
- [304, 'Column', 15, 35, 106, '', '00', null]
- [305, 'Column', 15, 36, 107, '', '00', null]
- [306, 'Column', 15, 37, 108, '', '00', null]
- [307, 'Column', 15, 38, 109, '', '00', null]
- [308, 'Column', 15, 39, 110, '', '00', null]
- [309, 'Column', 15, 40, 111, '', '00', null]
- [310, 'Column', 15, 41, 112, '', '00', null]
- [311, 'Column', 15, 42, 113, '', '00', null]
- [312, 'Column', 15, 43, 114, '', '00', null]
- [313, 'Column', 15, 44, 115, '', '00', null]
- [314, 'Column', 15, 45, 116, '', '00', null]
- [315, 'Column', 15, 46, 117, '', '00', null]
- [316, 'Column', 15, 47, 118, '', '00', null]
- [317, 'Column', 15, 48, 119, '', '00', null]
- [318, 'Column', 15, 49, 120, '', '00', null]
- [319, 'Column', 15, 50, 121, '', '00', null]
- [320, 'Column', 15, 51, 122, '', '00', null]
- [321, 'ResultRow', 72, 51, 0, '', '00', null]
- [322, 'Prev', 15, 269, 0, '', '00', null]
- [323, 'Halt', 0, 0, 0, '', '00', null]
- [324, 'Integer', 1, 18, 0, '', '00', null]
- [325, 'Integer', 1, 50, 0, '', '00', null]
- [326, 'Integer', 1, 52, 0, '', '00', null]
- [327, 'Integer', 1, 54, 0, '', '00', null]
- [328, 'Real', 0, 134, 0, '100', '00', null]
- [329, 'Real', 0, 135, 0, '5.28000020980835', '00', null]
- [330, 'Real', 0, 136, 0, '100.010002136', '00', null]
- [331, 'Integer', 180, 137, 0, '', '00', null]
- [332, 'Real', 0, 140, 0, '-5.796658992767334', '00', null]
- [333, 'Real', 0, 141, 0, '360', '00', null]
- [334, 'Integer', 360, 142, 0, '', '00', null]
- [335, 'Real', 0, 144, 0, '106.4992752075195', '00', null]
- [336, 'Real', 0, 145, 0, '720', '00', null]
- [337, 'Real', 0, 146, 0, '22.28000068664551', '00', null]
- [338, 'Integer', 0, 147, 0, '', '00', null]
- [339, 'Goto', 0, 1, 0, '', '00', null]
...
原始查询（以前使用像 (SELECT "max_click" FROM mopq) 这样的子查询，但与 CROSS JOIN:
explain
WITH sc AS ( -- shown count
SELECT "ref_id"
, "view_count"
FROM "userlistings"
WHERE "user_id" = 'af07e444-44f3-4116-833e-90af7f24ffa0'
), msc AS (
SELECT GREATEST(1,MAX("view_count")) "max_view"
FROM sc
)
,
opq AS (
SELECT "cat_id"
, "click_interest" -- SPEC-Q
, "purchase_interest" -- SPEC-P
, "message_interest" -- SPEC-O
FROM "usercats"
WHERE "user_id" = 'af07e444-44f3-4116-833e-90af7f24ffa0'
), mopq AS (
SELECT GREATEST(1,MAX("click_interest")) "max_click"
, GREATEST(1,MAX("purchase_interest")) "max_purchase"
, GREATEST(1,MAX("message_interest")) "max_inquiry"
FROM opq
)
SELECT "initial_cache"
+ (IFNULL(msc."max_view",1) - IFNULL(sc."view_count",0)) / IFNULL(msc."max_view",1) * 100.0 * 5.28000020980835/100.010002136
+ ((180-abs("lat" - -5.796658992767334))/360.0 + (360-abs("long" - 106.49927520751953))/720.0) * 100.0 * 22.280000686645508/100.010002136
+ IFNULL("message_interest",0) / IFNULL(mopq."max_inquiry",1) * 100.0 * 0/100.010002136
+ IFNULL("purchase_interest",0) / IFNULL(mopq."max_purchase",1) * 100.0 * 5.28000020980835/100.010002136
+ IFNULL("click_interest",0) / IFNULL(mopq."max_click",1) * 100.0 * 0/100.010002136, *
FROM "listings"
LEFT JOIN sc
ON "listings"."ref_id" = sc."ref_id"
CROSS JOIN msc
LEFT JOIN opq
ON "listings"."categories" = opq."cat_id"
CROSS JOIN mopq
WHERE "ref_type" = 1
ORDER BY 1 DESC LIMIT 5 OFFSET 0
这个查询的持续时间有点奇怪（在 go 程序中测量，但每次我需要更改查询时部署都会花费很多时间）：
ref_type = 1 (3538 rows) 587ms
ref_type = 5 ( 886 rows) 142ms
ref_type = 3 ( 104 rows) 9ms
ref_type = 6 (1608 rows) 276ms
没有本地（即 SQL 类）方法来衡量查询执行时间。但是，您可以将查询包装在跟踪时间的 Lua 函数中（使用 os Lua 模块）。示例取自 SQL reference:
function main_function()
local string_value, t, sql_statement
for i = 1,1000000, 1 do
string_value = string_function()
sql_statement = "INSERT INTO tester VALUES (" .. i .. ",'" .. string_value .. "')"
box.execute(sql_statement)
end
end
start_time = os.clock()
main_function()
end_time = os.clock()
'insert done in ' .. end_time - start_time .. ' seconds'
欢迎在 github 上打开功能请求：https://github.com/tarantool/tarantool/issues/new
同意这是不幸和不便的，我们计划在相当短的时间内让它变得更加方便。
作为今天的变通办法，我建议您启用 VDBE_PROFILE 并重新编译 Tarantool，这将生成带有 运行 注释的时间信息 VDBE 查询执行到 [=12] 的日志=] 文件，您可以在其中看到计时和计数器。
diff --git a/src/box/CMakeLists.txt b/src/box/CMakeLists.txt
index 999ac4749..0126f5af3 100644
--- a/src/box/CMakeLists.txt
+++ b/src/box/CMakeLists.txt
@@ -222,6 +222,7 @@ if(CMAKE_BUILD_TYPE STREQUAL "Debug")
add_definitions(-DSQL_DEBUG=1)
endif()
add_definitions(-DSQL_TEST=1)
+add_definitions(-DVDBE_PROFILE=1)
set(EXT_SRC_DIR ${CMAKE_SOURCE_DIR}/extra)
set(EXT_BIN_DIR ${CMAKE_BINARY_DIR}/extra)
根据 NikitaRock 的回答修改，创建一个像这样的辅助函数 T:
> function T(sql_statement)
start_time = os.clock()
res = box.execute(sql_statement)
end_time = os.clock()
return box.tuple.new(res, 'Query done in ' .. string.format("%.2f",(end_time - start_time)*1000) .. ' ms')
end
> T 'SELECT COUNT(*) FROM "listings" WHERE "ref_type" = 6;'
---
- [{'metadata': [{'name': 'COLUMN_1', 'type': 'integer'}], 'rows': [[1608]]}, 'Query
done in 0.49 ms']
...