[pgpool-general: 1840] Re: Error in pgpool log file: ERROR: pid 13491: delete_cache_on_memcached: NOT FOUND

Thu Jun 13 08:11:13 JST 2013

> Hi;
> We are using pgpool II (3.2.4), memcached(1.2.6-5.17.1) and libmemcached(1.0.17) on updated SLES 11 SP2 server which is connected to Master/Slave 3 node Postgresql 9.1.9 Cluster. 
> 
> Caching and Master/Slave Setup works great but we noticed that we started to get some delete_cache_on_memcached erros on logs. 
> 
> 2013-06-12 15:44:03 ERROR: pid 13710: delete_cache_on_memcached: NOT FOUND
> 2013-06-12 15:44:03 ERROR: pid 13710: delete_cache_on_memcached: NOT FOUND
> 2013-06-12 15:44:03 ERROR: pid 13710: delete_cache_on_memcached: NOT FOUND
> 2013-06-12 15:44:03 ERROR: pid 13710: delete_cache_on_memcached: NOT FOUND
> 2013-06-12 15:44:03 ERROR: pid 13710: delete_cache_on_memcached: NOT FOUND
> 2013-06-12 15:44:03 ERROR: pid 13710: delete_cache_on_memcached: NOT FOUND
> 2013-06-12 15:44:03 ERROR: pid 13710: delete_cache_on_memcached: NOT FOUND
> 2013-06-12 15:44:03 ERROR: pid 13710: delete_cache_on_memcached: NOT FOUND

These show that pgpool tries to remove the cache entry because DML is
executed in the session. Pgpool looks into oiddir and if it finds a
file whose name is the oid of the table updated in the DML, then
retrieve cache keys from the oid file and tries to remove cache
entries in memcached. But for some reason it fails to remove.  (Oid
files are created while pgpool creates news cache entry because SELECT
is execute).

I think if a session executes SELECT, and at the same time another
session executes DML, there could be a race condition because
memcached operations are not atomic. Do you see this errors while
there are concurrent pgpool sessions?

If that's the case, mabe I should change the error messags above to
"DEBUG" because it's a normal behavior.

> Also i notice that oid files are generating under memqcache_oiddir dir like below.

They are normal as I explained above.

> pgpool:~ # ls -lA /var/log/pgpool/oiddir/16386/
> total 25496
> -rw------- 1 root root  842784 Jun 12 15:55 16429
> -rw------- 1 root root 1000992 Jun 12 15:55 16435
> -rw------- 1 root root 3231488 Jun 12 15:55 16441
> -rw------- 1 root root   20032 Jun 12 15:54 16447
> -rw------- 1 root root 4647456 Jun 12 15:55 16466
> -rw------- 1 root root 1178368 Jun 12 15:55 16474
> -rw------- 1 root root    2496 Jun 12 15:55 16479
> -rw------- 1 root root 1115136 Jun 12 15:55 16485
> -rw------- 1 root root 3127840 Jun 12 15:55 16490
> -rw------- 1 root root 1299424 Jun 12 15:55 16502
> -rw------- 1 root root     128 Jun 12 10:31 16508
> -rw------- 1 root root     160 Jun 12 10:31 16516
> -rw------- 1 root root 3381600 Jun 12 15:55 16549
> -rw------- 1 root root 4466816 Jun 12 15:55 16556
> -rw------- 1 root root   85664 Jun 12 15:55 16578
> -rw------- 1 root root    3168 Jun 12 15:19 16621
> -rw------- 1 root root    1088 Jun 12 10:46 16642
> -rw------- 1 root root   10432 Jun 12 15:54 16648
> -rw------- 1 root root    4960 Jun 12 15:19 16677
> -rw------- 1 root root   10432 Jun 12 15:54 16695
> -rw------- 1 root root   10432 Jun 12 15:54 16704
> -rw------- 1 root root      64 Jun 12 15:55 16756
> -rw------- 1 root root 1553024 Jun 12 15:55 16770
> 
> I also wrote our config below:
> 
> So how could i fix this "delete_cache_on_memcached: NOT FOUND " error, is this a known bug or this issue occurs from my setup? Does anyone experience issue like me? 
> 
> Regards
> Özhan
> 
> ##############################
> 
> 
> listen_addresses = '192.168.0.1'
> port = 5437
> socket_dir = '/tmp'
> # - pgpool Communication Manager Connection Settings -
> pcp_port = 9898
> pcp_socket_dir = '/tmp'
> 
> backend_hostname0 = '192.168.1.1'
> backend_port0 = 5432
> backend_weight0 = 2 
> backend_data_directory0 = '/u02/pgdata91'
> backend_flag0 = 'ALLOW_TO_FAILOVER'
> 
> backend_hostname1 = '192.168.1.2'
> backend_port1 = 5432
> backend_weight1 = 30
> backend_data_directory1 = '/u02/pgdata91'
> backend_flag1 = 'ALLOW_TO_FAILOVER'
> 
> backend_hostname2 = '192.168.1.3'
> backend_port2 = 5432
> backend_weight2 = 30
> backend_data_directory2 = '/u02/pgdata91'
> backend_flag2 = 'ALLOW_TO_FAILOVER'
> 
> # - Authentication -
> enable_pool_hba = off
> pool_passwd = 'pool_passwd'
> authentication_timeout = 60
> # - SSL Connections -
> ssl = off
> #ssl_key = './server.key'
> #ssl_cert = './server.cert'
> #ssl_ca_cert = ''
> #ssl_ca_cert_dir = ''
> 
> #------------------------------------------------------------------------------
> # POOLS
> #------------------------------------------------------------------------------
> 
> # - Pool size -
> num_init_children = 64
> max_pool = 2
> child_life_time = 300
> child_max_connections = 1000
> connection_life_time = 600
> client_idle_limit = 0
> 
> 
> #------------------------------------------------------------------------------
> # LOGS
> #------------------------------------------------------------------------------
> 
> # - Where to log -
> 
> log_destination = 'syslog'
> print_timestamp = on
> log_connections = off
> log_hostname = off
> log_statement = off
> log_per_node_statement = on
> log_standby_delay = 'none'
> # - Syslog specific -
> syslog_facility = 'LOCAL0'
> syslog_ident = 'pgpool'
> 
> # - Debug -
> debug_level = 0
> #------------------------------------------------------------------------------
> # FILE LOCATIONS
> #------------------------------------------------------------------------------
> pid_file_name = '/var/run/pgpool.pid'
> logdir = '/tmp'
> 
> #------------------------------------------------------------------------------
> # CONNECTION POOLING
> #------------------------------------------------------------------------------
> connection_cache = on
> reset_query_list = 'ABORT; DISCARD ALL'
> 
> #------------------------------------------------------------------------------
> # REPLICATION MODE
> #------------------------------------------------------------------------------
> replication_mode = off
> replicate_select = off
> insert_lock = off
> lobj_lock_table = ''
> # - Degenerate handling -
> replication_stop_on_mismatch = off
> failover_if_affected_tuples_mismatch = off
> 
> 
> #------------------------------------------------------------------------------
> # LOAD BALANCING MODE
> #------------------------------------------------------------------------------
> 
> load_balance_mode = on
> ignore_leading_white_space = on
> white_function_list = ''
> black_function_list = 'currval,lastval,nextval,setval'
> 
> #------------------------------------------------------------------------------
> # MASTER/SLAVE MODE
> #------------------------------------------------------------------------------
> master_slave_mode = on
> master_slave_sub_mode = 'stream'
> # - Streaming -
> sr_check_period = 0
> sr_check_user = 'postgres'
> sr_check_password = ''
> delay_threshold = 0
> # - Special commands -
> follow_master_command = ''
> 
> 
> #------------------------------------------------------------------------------
> # PARALLEL MODE
> #------------------------------------------------------------------------------
> parallel_mode = off
> pgpool2_hostname = ''
> 
> #------------------------------------------------------------------------------
> # HEALTH CHECK
> #------------------------------------------------------------------------------
> 
> health_check_period = 10
> health_check_timeout = 20
> health_check_user = 'pgozi91'
> health_check_password = ''
> health_check_max_retries = 0
> health_check_retry_delay = 1
> 
> #------------------------------------------------------------------------------
> # FAILOVER AND FAILBACK
> #------------------------------------------------------------------------------
> failover_command = '/usr/local/bin/failover.sh %d %H'
> failback_command = ''
> fail_over_on_backend_error = on
> 
> #------------------------------------------------------------------------------
> # ONLINE RECOVERY
> #------------------------------------------------------------------------------
> recovery_user = 'nobody'
> recovery_password = ''
> recovery_1st_stage_command = ''
> recovery_2nd_stage_command = ''
> recovery_timeout = 90
> client_idle_limit_in_recovery = 0
> 
> #------------------------------------------------------------------------------
> # WATCHDOG
> #------------------------------------------------------------------------------
> use_watchdog = off 
> trusted_servers = ''
> delegate_IP = ''
> wd_hostname = ''
> wd_port = 9000
> wd_interval = 10
> ping_path = '/bin'
> ifconfig_path = '/sbin'
> if_up_cmd = 'ifconfig eth0:0 inet $_IP_$ netmask 255.255.255.0'
> if_down_cmd = 'ifconfig eth0:0 down'
> arping_path = '/usr/sbin'           # arping command path
> arping_cmd = 'arping -U $_IP_$ -w 1'
> wd_life_point = 3
> wd_lifecheck_query = 'SELECT 1'
> 
> 
> #------------------------------------------------------------------------------
> # OTHERS
> #------------------------------------------------------------------------------
> relcache_expire = 0
> relcache_size = 256
> check_temp_table = off
> 
> #------------------------------------------------------------------------------
> # ON MEMORY QUERY MEMORY CACHE
> #------------------------------------------------------------------------------
> memory_cache_enabled = on
> memqcache_method = 'memcached'
> 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 = '/var/log/pgpool/oiddir'
> white_memqcache_table_list = ''
> black_memqcache_table_list = ''
> _______________________________________________
> pgpool-general mailing list
> pgpool-general at pgpool.net
> http://www.pgpool.net/mailman/listinfo/pgpool-general