[pgpool-general-jp: 1227] スキーマ名を指定する必要がある場合のオンメモリクエリキャッシュ機能の挙動について

hiroin ap2 @ ap2.sakura.ne.jp
2013年 11月 10日 (日) 21:02:52 JST


お世話になります。
神谷と申します。

オンメモリクエリキャッシュ機能を有効にしている状態で、
 スキーマ名.テーブル名
のテーブルを更新してもキャッシュを読み込んでしまいます。
スキーマ名を指定しない場合は問題なく動作しております。

設定ミスかバグだと思っております。
設定ミスでしたらミスの箇所をご教示頂けますと幸いです。

以下に各種情報を記載させて頂きます。

[環境]
PostgreSQL9.3.1
pgpool-II-3.3.1

[pgpoolのオンメモリクエリキャッシュ機能の設定]
memory_cache_enabled = on
memqcache_method = 'shmem'
memqcache_memcached_host = 'localhost'
memqcache_memcached_port = 11211
memqcache_total_size = 67108864
memqcache_max_num_cache = 1000000
memqcache_expire = 0
memqcache_auto_cache_invalidation = on
memqcache_maxcache = 409600
memqcache_cache_block_size = 1048576
memqcache_oiddir = '/home/ap2/oiddir'
white_memqcache_table_list = ''
black_memqcache_table_list = ''

[現象を確認したテーブル]
# \d bookstore.users
                                         テーブル "bookstore.users"
         列          |           型           |                            修飾語
---------------------+------------------------+--------------------------------------------------------------
 id                  | integer                | not null default nextval('bookstore.users_id_seq'::regclass)
 username            | character varying(50)  | not null
 password            | character varying(255) | not null
 group               | integer                | not null default 1
 email               | character varying(255) | not null default ''::character varying
 last_login          | character varying(50)  | not null
 login_hash          | character varying(255) | not null
 profile_fields      | text                   | not null default ''::text
 created_at          | integer                | not null default 0
 updated_at          | integer                | not null default 0
 password_miss_count | integer                | not null default 0

[現象を確認したクエリ]
# SELECT password_miss_count FROM bookstore.users WHERE username = 'テストユーザー' ;
 password_miss_count
---------------------
                   1

ap2=# SELECT password_miss_count FROM bookstore.users WHERE username = 'テストユーザー' ;
 password_miss_count
---------------------
                   1

ap2=# UPDATE bookstore.users SET password_miss_count = 0 WHERE username = 'テストユーザー' ;
UPDATE 1

ap2=# SELECT password_miss_count FROM bookstore.users WHERE username = 'テストユーザー' ;
 password_miss_count
---------------------
                   1

ap2=# SELECT password_miss_count FROM bookstore.users WHERE username = 'テストユーザー' ;
 password_miss_count
---------------------
                   1

[現象を確認したクエリを実行したときのログ]
2013-11-10 19:57:32 DEBUG: pid 30188: statement2: UPDATE bookstore.users SET password_miss_count = 0 WHERE username = 'テストユーザー' ;
2013-11-10 19:57:32 DEBUG: pid 30188: pool_set_query_in_progress: done
2013-11-10 19:57:32 DEBUG: pid 30188: do_query: extended:0 query:SELECT oid FROM pg_class WHERE relname = 'bookstore.users'
2013-11-10 19:57:32 DEBUG: pid 30188: do_query: kind: T
2013-11-10 19:57:32 DEBUG: pid 30188: do_query: row description received
2013-11-10 19:57:32 DEBUG: pid 30188: num_fileds: 1
2013-11-10 19:57:32 DEBUG: pid 30188: do_query: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: do_query: Command complete received
2013-11-10 19:57:32 DEBUG: pid 30188: do_query: kind: Z
2013-11-10 19:57:32 DEBUG: pid 30188: do_query: Ready for query
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: Query: BEGIN
2013-11-10 19:57:32 DEBUG: pid 30188: wait_for_query_response: waiting for backend 0 completing the query
2013-11-10 19:57:32 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: len:a000000
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: kind: Z
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: transaction state: T
2013-11-10 19:57:32 DEBUG: pid 30188: pool_unset_writing_transaction: done
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: Query: BEGIN
2013-11-10 19:57:32 DEBUG: pid 30188: wait_for_query_response: waiting for backend 1 completing the query
2013-11-10 19:57:32 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: len:a000000
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: kind: Z
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: transaction state: T
2013-11-10 19:57:32 DEBUG: pid 30188: pool_unset_writing_transaction: done
2013-11-10 19:57:32 DEBUG: pid 30188: wait_for_query_response: waiting for backend 0 completing the query
2013-11-10 19:57:32 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: wait_for_query_response: waiting for backend 1 completing the query
2013-11-10 19:57:32 DEBUG: pid 30188: pool_unset_skip_reading_from_backends: done
2013-11-10 19:57:32 DEBUG: pid 30188: read_kind_from_backend: kind: C from 0 th backend
2013-11-10 19:57:32 DEBUG: pid 30188: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 2
2013-11-10 19:57:32 DEBUG: pid 30188: read_kind_from_backend: kind: C from 1 th backend
2013-11-10 19:57:32 DEBUG: pid 30188: read_kind_from_backend: read kind from 1 th backend C NUM_BACKENDS: 2
2013-11-10 19:57:32 DEBUG: pid 30188: ProcessBackendResponse: kind from backend: C
2013-11-10 19:57:32 DEBUG: pid 30188: pool_set_command_success: done
2013-11-10 19:57:32 DEBUG: pid 30188: read_kind_from_backend: kind: Z from 0 th backend
2013-11-10 19:57:32 DEBUG: pid 30188: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 2
2013-11-10 19:57:32 DEBUG: pid 30188: read_kind_from_backend: kind: Z from 1 th backend
2013-11-10 19:57:32 DEBUG: pid 30188: read_kind_from_backend: read kind from 1 th backend Z NUM_BACKENDS: 2
2013-11-10 19:57:32 DEBUG: pid 30188: ProcessBackendResponse: kind from backend: Z
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: Query: COMMIT
2013-11-10 19:57:32 DEBUG: pid 30188: wait_for_query_response: waiting for backend 1 completing the query
2013-11-10 19:57:32 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: len:b000000
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: kind: Z
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: Query: COMMIT
2013-11-10 19:57:32 DEBUG: pid 30188: wait_for_query_response: waiting for backend 0 completing the query
2013-11-10 19:57:32 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: kind: C
2013-11-10 19:57:32 DEBUG: pid 30188: len:b000000
2013-11-10 19:57:32 DEBUG: pid 30188: do_command: kind: Z
2013-11-10 19:57:32 DEBUG: pid 30188: pool_read_message_length: slot: 0 length: 5
2013-11-10 19:57:32 DEBUG: pid 30188: pool_read_message_length: slot: 1 length: 5
2013-11-10 19:57:32 DEBUG: pid 30188: ReadyForQuery: transaction state:T
2013-11-10 19:57:32 DEBUG: pid 30188: ReadyForQuery: transaction state:I
2013-11-10 19:57:32 DEBUG: pid 30188: pool_unset_query_in_progress: done
2013-11-10 19:57:32 DEBUG: pid 30188: pool_unset_query_in_progress: done
2013-11-10 19:57:32 DEBUG: pid 30188: ProcessBackendResponse: Ready For Query
2013-11-10 19:57:36 DEBUG: pid 30188: ProcessFrontendResponse: kind from frontend Q(51)
2013-11-10 19:57:36 DEBUG: pid 30188: pool_unset_doing_extended_query_message: done
2013-11-10 19:57:36 DEBUG: pid 30188: statement2: SELECT password_miss_count FROM bookstore.users WHERE username = 'テストユーザー' ;
2013-11-10 19:57:36 DEBUG: pid 30188: encode_key: username testdb
2013-11-10 19:57:36 DEBUG: pid 30188: encode_key: database_name testdb
2013-11-10 19:57:36 DEBUG: pid 30188: encode_key: query SELECT password_miss_count FROM bookstore.users WHERE username = 'テストユーザー' ;
2013-11-10 19:57:36 DEBUG: pid 30188: encode_key: `testdbSELECT password_miss_count FROM bookstore.users WHERE username = 'テストユーザー' ;testdb' -> `df22c47532a03d5740cc31b64d683915'
2013-11-10 19:57:36 DEBUG: pid 30188: pool_fetch_cache: search key ==df22c47532a03d5740cc31b64d683915==
2013-11-10 19:57:36 DEBUG: pid 30188: pool_fetch_cache: query=SELECT password_miss_count FROM bookstore.users WHERE username = 'テストユーザー' ; len:71
2013-11-10 19:57:36 DEBUG: pid 30188: send_cached_messages: T len: 44
2013-11-10 19:57:36 DEBUG: pid 30188: send_message: kind=T, len=44, data=0xa93fd5
2013-11-10 19:57:36 DEBUG: pid 30188: send_cached_messages: D len: 11
2013-11-10 19:57:36 DEBUG: pid 30188: send_message: kind=D, len=11, data=0xa94002
2013-11-10 19:57:36 DEBUG: pid 30188: send_cached_messages: C len: 13
2013-11-10 19:57:36 DEBUG: pid 30188: send_message: kind=C, len=13, data=0xa9400e
2013-11-10 19:57:36 DEBUG: pid 30188: send_message: kind=Z, len=5, data=0x7fff4b4be45f
2013-11-10 19:57:36 DEBUG: pid 30188: pool_fetch_from_memory_cache: a query result found in the query cache, SELECT password_miss_count FROM bookstore.users WHERE username = 'テストユーザー' ;


[(参考)同じDBでpublicスキーマのテーブルを更新したときのログ]
2013-11-10 19:56:19 DEBUG: pid 30188: statement2: UPDATE myuser SET password_miss_count = 0 WHERE uid = 'テストユーザー' ;
2013-11-10 19:56:19 DEBUG: pid 30188: pool_set_query_in_progress: done
2013-11-10 19:56:19 DEBUG: pid 30188: pool_extract_table_oids: table:"myuser" oid:16447
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: Query: BEGIN
2013-11-10 19:56:19 DEBUG: pid 30188: wait_for_query_response: waiting for backend 0 completing the query
2013-11-10 19:56:19 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: len:a000000
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: kind: Z
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: transaction state: T
2013-11-10 19:56:19 DEBUG: pid 30188: pool_unset_writing_transaction: done
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: Query: BEGIN
2013-11-10 19:56:19 DEBUG: pid 30188: wait_for_query_response: waiting for backend 1 completing the query
2013-11-10 19:56:19 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: len:a000000
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: kind: Z
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: transaction state: T
2013-11-10 19:56:19 DEBUG: pid 30188: pool_unset_writing_transaction: done
2013-11-10 19:56:19 DEBUG: pid 30188: wait_for_query_response: waiting for backend 0 completing the query
2013-11-10 19:56:19 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: wait_for_query_response: waiting for backend 1 completing the query
2013-11-10 19:56:19 DEBUG: pid 30188: pool_unset_skip_reading_from_backends: done
2013-11-10 19:56:19 DEBUG: pid 30188: read_kind_from_backend: kind: C from 0 th backend
2013-11-10 19:56:19 DEBUG: pid 30188: read_kind_from_backend: read kind from 0 th backend C NUM_BACKENDS: 2
2013-11-10 19:56:19 DEBUG: pid 30188: read_kind_from_backend: kind: C from 1 th backend
2013-11-10 19:56:19 DEBUG: pid 30188: read_kind_from_backend: read kind from 1 th backend C NUM_BACKENDS: 2
2013-11-10 19:56:19 DEBUG: pid 30188: ProcessBackendResponse: kind from backend: C
2013-11-10 19:56:19 DEBUG: pid 30188: pool_set_command_success: done
2013-11-10 19:56:19 DEBUG: pid 30188: read_kind_from_backend: kind: Z from 0 th backend
2013-11-10 19:56:19 DEBUG: pid 30188: read_kind_from_backend: read kind from 0 th backend Z NUM_BACKENDS: 2
2013-11-10 19:56:19 DEBUG: pid 30188: read_kind_from_backend: kind: Z from 1 th backend
2013-11-10 19:56:19 DEBUG: pid 30188: read_kind_from_backend: read kind from 1 th backend Z NUM_BACKENDS: 2
2013-11-10 19:56:19 DEBUG: pid 30188: ProcessBackendResponse: kind from backend: Z
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: Query: COMMIT
2013-11-10 19:56:19 DEBUG: pid 30188: wait_for_query_response: waiting for backend 1 completing the query
2013-11-10 19:56:19 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: len:b000000
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: kind: Z
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: Query: COMMIT
2013-11-10 19:56:19 DEBUG: pid 30188: wait_for_query_response: waiting for backend 0 completing the query
2013-11-10 19:56:19 DEBUG: pid 30188: detect_error: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: kind: C
2013-11-10 19:56:19 DEBUG: pid 30188: len:b000000
2013-11-10 19:56:19 DEBUG: pid 30188: do_command: kind: Z
2013-11-10 19:56:19 DEBUG: pid 30188: pool_read_message_length: slot: 0 length: 5
2013-11-10 19:56:19 DEBUG: pid 30188: pool_read_message_length: slot: 1 length: 5
2013-11-10 19:56:19 DEBUG: pid 30188: ReadyForQuery: transaction state:T
2013-11-10 19:56:19 DEBUG: pid 30188: ReadyForQuery: transaction state:I
2013-11-10 19:56:19 DEBUG: pid 30188: pool_invalidate_query_cache: dboid 16385
2013-11-10 19:56:19 DEBUG: pid 30188: pool_invalidate_query_cache: deleting cacheid:0 itemid:0
2013-11-10 19:56:19 DEBUG: pid 30188: pool_delete_item_shmem_cache: cacheid:0 itemid:0
2013-11-10 19:56:19 DEBUG: pid 30188: pool_reset_memqcache_buffer: discard: 0xa93430
2013-11-10 19:56:19 DEBUG: pid 30188: pool_discard_query_cache_array: num_caches: 0
2013-11-10 19:56:19 DEBUG: pid 30188: pool_reset_memqcache_buffer: create: 0xa93430
2013-11-10 19:56:19 DEBUG: pid 30188: pool_reset_memqcache_buffer: discard temp buffer of 0xa95630 (UPDATE myuser SET password_miss_count = 0 WHERE uid = 'テストユーザー' 
2013-11-10 19:56:19 DEBUG: pid 30188: pool_unset_query_in_progress: done
2013-11-10 19:56:19 DEBUG: pid 30188: pool_unset_query_in_progress: done
2013-11-10 19:56:19 DEBUG: pid 30188: ProcessBackendResponse: Ready For Query

よろしくお願いいたします。



pgpool-general-jp メーリングリストの案内