View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0000643Pgpool-IIBugpublic2020-08-28 10:452020-08-31 17:07
Reporter2381917 Assigned Tot-ishii  
PriorityhighSeveritymajorReproducibilityhave not tried
Status closedResolutionopen 
Product Version4.0.7 
Summary0000643: message length (24) in slot 2 does not match with slot 0(25)
DescriptionHi Team,

We are getting below error frequently. I have restarted the Pgpool but still same error in the log.
Error:- message length (24) in slot 2 does not match with slot 0(25)

Log:-
2020-08-28 04:45:07: pid 28309: DETAIL: message length (24) in slot 1 does not match with slot 0(25)
2020-08-28 04:45:07: pid 28309: LOG: reading message length
2020-08-28 04:45:07: pid 28309: DETAIL: message length (24) in slot 2 does not match with slot 0(25)
2020-08-28 04:45:08: pid 31806: LOG: md5 authentication successful with frontend
2020-08-28 04:45:08: pid 28277: LOG: md5 authentication successful with frontend
2020-08-28 04:45:08: pid 28277: LOG: reading message length
2020-08-28 04:45:08: pid 28277: DETAIL: message length (24) in slot 1 does not match with slot 0(25)
2020-08-28 04:45:08: pid 28277: LOG: reading message length
2020-08-28 04:45:08: pid 28277: DETAIL: message length (24) in slot 2 does not match with slot 0(25)
2020-08-28 04:45:08: pid 28277: ERROR: unable to read data from frontend
2020-08-28 04:45:08: pid 28277: DETAIL: EOF encountered with frontend
TagsNo tags attached.

Activities

2381917

2020-08-28 15:15

reporter   ~0003528

Can you please let me know, when such types of error comes or what does mean it.

t-ishii

2020-08-29 11:40

developer   ~0003531

> Error:- message length (24) in slot 2 does not match with slot 0(25)
Backend 0 and backend 2 does not have identical password or other data for authentication. To know what is wrong, we need:
pool_hba,.conf
pgpool.conf
pg_hba.conf (both backend 0 and 2)

2381917

2020-08-30 00:31

reporter   ~0003532

Hi,
Required files has been attached.
I would like to provide below information:-
We have 3 nodes cluster And pgpool is also setup on a node in the same cluster.
The pg_hba.conf file is same for all three nodes, so attached only for single node.

The same configuration (all setup) we are using on another cluster and that is working fine. Getting this error only in one cluster.
pg_hba.conf (4,839 bytes)
pgpool.conf (43,871 bytes)
pool_hba.conf (3,500 bytes)

t-ishii

2020-08-30 07:55

developer   ~0003533

Last edited: 2020-08-30 08:28

 Which version of PostgreSQL are you using? Can you share pgpool.log with "log_min_messages = debug5" in pgpool.conf while the error happening?

2381917

2020-08-31 14:17

reporter   ~0003539

Hi,

The postgresql version is 10. And below is the log after changed the parameter log_min_messages to debug5.

2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: reading backend data packet kind
2020-08-31 08:10:41: pid 22186: DETAIL: backend:2 kind:'T'
2020-08-31 08:10:41: pid 22186: DEBUG: reading backend data packet kind
2020-08-31 08:10:41: pid 22186: DETAIL: backend:2 of 3 kind = 'T'
2020-08-31 08:10:41: pid 22186: DEBUG: read_kind_from_backend max_count:1.000000 num_executed_nodes:1
2020-08-31 08:10:41: pid 22186: DEBUG: processing backend response
2020-08-31 08:10:41: pid 22186: DETAIL: received kind 'T'(54) from backend
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_write: to frontend: kind:T po:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:10:41: pid 22186: DEBUG: pool_write: to frontend: length:163 po:5
2020-08-31 08:10:41: pid 22186: DEBUG: pool_flush_it: flush size: 168
2020-08-31 08:10:41: pid 22186: DEBUG: SimpleForwardToFrontend: packet:T length:163
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: reading backend data packet kind
2020-08-31 08:10:41: pid 22186: DETAIL: master node id: 2
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: reading backend data packet kind
2020-08-31 08:10:41: pid 22186: DETAIL: backend:2 kind:'C'
2020-08-31 08:10:41: pid 22186: DEBUG: reading backend data packet kind
2020-08-31 08:10:41: pid 22186: DETAIL: backend:2 of 3 kind = 'C'
2020-08-31 08:10:41: pid 22186: DEBUG: read_kind_from_backend max_count:1.000000 num_executed_nodes:1
2020-08-31 08:10:41: pid 22186: DEBUG: processing backend response
2020-08-31 08:10:41: pid 22186: DETAIL: received kind 'C'(43) from backend
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_write: to frontend: kind:C po:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:10:41: pid 22186: DEBUG: pool_write: to frontend: length:9 po:5
2020-08-31 08:10:41: pid 22186: DEBUG: pool_flush_it: flush size: 14
2020-08-31 08:10:41: pid 22186: DEBUG: session context: setting command success. DONE
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: reading backend data packet kind
2020-08-31 08:10:41: pid 22186: DETAIL: master node id: 2
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: reading backend data packet kind
2020-08-31 08:10:41: pid 22186: DETAIL: backend:2 kind:'Z'
2020-08-31 08:10:41: pid 22186: DEBUG: reading backend data packet kind
2020-08-31 08:10:41: pid 22186: DETAIL: backend:2 of 3 kind = 'Z'
2020-08-31 08:10:41: pid 22186: DEBUG: read_kind_from_backend max_count:1.000000 num_executed_nodes:1
2020-08-31 08:10:41: pid 22186: DEBUG: processing backend response
2020-08-31 08:10:41: pid 22186: DETAIL: received kind 'Z'(5a) from backend
2020-08-31 08:10:41: pid 22186: DEBUG: processing backend response
2020-08-31 08:10:41: pid 22186: DETAIL: Ready For Query received
2020-08-31 08:10:41: pid 22186: DEBUG: session context: clearing ignore till sync. DONE
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: reading message length
2020-08-31 08:10:41: pid 22186: DETAIL: slot: 2 length: 5
2020-08-31 08:10:41: pid 22186: DEBUG: pool_virtual_master_db_node_id: virtual_master_node_id:2 load_balance_node_id:2 PRIMARY_NODE_ID:0
2020-08-31 08:10:41: pid 22186: DEBUG: processing ReadyForQuery
2020-08-31 08:10:41: pid 22186: DETAIL: transaction state 'I'(49)
2020-08-31 08:10:41: pid 22186: DEBUG: pool_write: to frontend: kind:Z po:0
2020-08-31 08:10:41: pid 22186: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:10:41: pid 22186: DEBUG: pool_write: to frontend: kind:I po:5
2020-08-31 08:10:41: pid 22186: DEBUG: pool_flush_it: flush size: 6
2020-08-31 08:10:41: pid 22186: DEBUG: session context: unsetting query in progress. DONE
2020-08-31 08:10:41: pid 22186: DEBUG: pool_query_context_destroy: query context:0x1e67fc8 query: " SELECT "id",
                 "node_id",
                 "channel",
                 "data",
                 EXTRACT(EPOCH FROM "at" AT TIME ZONE 'UTC') AS "at",
                 EXTRACT(EPOCH FROM "nbf" AT TIME ZONE 'UTC') AS "nbf",
                 EXTRACT(EPOCH FROM CURRENT_TIMESTAMP(3) AT TIME ZONE 'UTC') AS "now"
            FROM "cluster_events"
           WHERE "channel" IN ('invalidations', 'balancer:targets', 'balancer:post_health', 'balancer:upstreams', 'proxy-cache:purge')
             AND "at" > TO_TIMESTAMP(1598549631.499) AT TIME ZONE 'UTC'
             AND "at" <= CURRENT_TIMESTAMP(3) AT TIME ZONE 'UTC'
        ORDER BY "at"
           LIMIT 1000
          OFFSET 0
        "
2020-08-31 08:10:41: pid 22186: DEBUG: session context: unsetting query in progress. DONE

2020-08-31 08:10:42: pid 21528: DEBUG: processing frontend response
2020-08-31 08:10:42: pid 21528: DETAIL: received kind 'Q'(51) from frontend
2020-08-31 08:10:42: pid 21528: DEBUG: session context: clearing doing extended query messaging. DONE
2020-08-31 08:10:42: pid 21528: DEBUG: session context: setting query in progress. DONE
2020-08-31 08:10:42: pid 21528: DEBUG: function call walker, function name: "date_part"
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: function call walker, function name: "timezone"
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: function call walker, function name: "date_part"
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: function call walker, function name: "timezone"
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: function call walker, function name: "date_part"
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: date_part
2020-08-31 08:10:42: pid 21528: DEBUG: function call walker, function name: "timezone"
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: function call walker, function name: "timezone"
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: function call walker, function name: "to_timestamp"
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: to_timestamp
2020-08-31 08:10:42: pid 21528: DEBUG: function call walker, function name: "timezone"
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^currval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^lastval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^nextval$) not matched: timezone
2020-08-31 08:10:42: pid 21528: DEBUG: comparing function name in blacklist/whitelist regex array
2020-08-31 08:10:42: pid 21528: DETAIL: pattern_compare: black_function_list (^setval$) not matched: timezone

t-ishii

2020-08-31 14:30

developer   ~0003540

I needed log message including below:
message length (24) in slot 2 does not match with slot 0(25)
But the above does not include the message.

2381917

2020-08-31 14:50

reporter   ~0003541

Hi,
Please find below log:

2020-08-31 08:38:22: pid 5623: DETAIL: Protocol Major: 3 Minor: 0 database: transactiondb user: trnsx_services
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:R po:0
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:9
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 13
2020-08-31 08:38:22: pid 5623: LOG: md5 authentication successful with frontend
2020-08-31 08:38:22: pid 5623: DEBUG: creating new connection to backend
2020-08-31 08:38:22: pid 5623: DETAIL: connecting 0 backend
2020-08-31 08:38:22: pid 5623: DEBUG: creating new connection to backend
2020-08-31 08:38:22: pid 5623: DETAIL: connecting 1 backend
2020-08-31 08:38:22: pid 5623: DEBUG: creating new connection to backend
2020-08-31 08:38:22: pid 5623: DETAIL: connecting 2 backend
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 121
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 121
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 121
2020-08-31 08:38:22: pid 5623: DEBUG: pool_read: read 13 bytes from backend 0
2020-08-31 08:38:22: pid 5623: DEBUG: pool_read: read 13 bytes from backend 1
2020-08-31 08:38:22: pid 5623: DEBUG: pool_read: read 13 bytes from backend 2
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: slot: 0 length: 12
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: slot: 1 length: 12
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: slot: 2 length: 12
2020-08-31 08:38:22: pid 5623: DEBUG: authentication backend
2020-08-31 08:38:22: pid 5623: DETAIL: auth kind:5
2020-08-31 08:38:22: pid 5623: DEBUG: authentication backend: 0
2020-08-31 08:38:22: pid 5623: DETAIL: trying md5 authentication
2020-08-31 08:38:22: pid 5623: DEBUG: performing md5 authentication
2020-08-31 08:38:22: pid 5623: DETAIL: DB node id: 0 salt: dbc29ea6
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to backend: 0 kind:p
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 41
2020-08-31 08:38:22: pid 5623: DEBUG: pool_read: read 325 bytes from backend 0
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:R po:0
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 9
2020-08-31 08:38:22: pid 5623: DEBUG: authentication backend: 1
2020-08-31 08:38:22: pid 5623: DETAIL: trying md5 authentication
2020-08-31 08:38:22: pid 5623: DEBUG: performing md5 authentication
2020-08-31 08:38:22: pid 5623: DETAIL: DB node id: 1 salt: 25954654
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to backend: 1 kind:p
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 41
2020-08-31 08:38:22: pid 5623: DEBUG: pool_read: read 324 bytes from backend 1
2020-08-31 08:38:22: pid 5623: DEBUG: authentication backend: 2
2020-08-31 08:38:22: pid 5623: DETAIL: trying md5 authentication
2020-08-31 08:38:22: pid 5623: DEBUG: performing md5 authentication
2020-08-31 08:38:22: pid 5623: DETAIL: DB node id: 2 salt: 4ead6c1b
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to backend: 2 kind:p
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 41
2020-08-31 08:38:22: pid 5623: DEBUG: pool_read: read 324 bytes from backend 2
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:S po:0
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 0 length: 22
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 1 length: 22
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 2 length: 22
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"application_name" value:""
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:1 name:"application_name" value:""
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:2 name:"application_name" value:""
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:18 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 23
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:S po:0
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 0 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 1 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 2 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"client_encoding" value:"UTF8"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:1 name:"client_encoding" value:"UTF8"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:2 name:"client_encoding" value:"UTF8"
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:21 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 26
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:S po:0
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 0 length: 23
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 1 length: 23
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 2 length: 23
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"DateStyle" value:"ISO, MDY"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:1 name:"DateStyle" value:"ISO, MDY"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:2 name:"DateStyle" value:"ISO, MDY"
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:19 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 24
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:S po:0
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 0 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 1 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 2 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"integer_datetimes" value:"on"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:1 name:"integer_datetimes" value:"on"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:2 name:"integer_datetimes" value:"on"
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:21 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 26
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:S po:0
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 0 length: 27
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 1 length: 27
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 2 length: 27
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"IntervalStyle" value:"postgres"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:1 name:"IntervalStyle" value:"postgres"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:2 name:"IntervalStyle" value:"postgres"
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:23 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 28
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:S po:0
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 0 length: 21
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 1 length: 21
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 2 length: 21
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"is_superuser" value:"off"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:1 name:"is_superuser" value:"off"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:2 name:"is_superuser" value:"off"
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:17 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 22
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:S po:0
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 0 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 1 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 2 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"server_encoding" value:"UTF8"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:1 name:"server_encoding" value:"UTF8"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:2 name:"server_encoding" value:"UTF8"
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:21 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 26
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:S po:0
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 0 length: 25
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 1 length: 24
2020-08-31 08:38:22: pid 5623: LOG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: message length (24) in slot 1 does not match with slot 0(25)
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 2 length: 24
2020-08-31 08:38:22: pid 5623: LOG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: message length (24) in slot 2 does not match with slot 0(25)
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"server_version" value:"10.10"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:1 name:"server_version" value:"10.7"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:2 name:"server_version" value:"10.7"
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:21 po:5
2020-08-31 08:38:22: pid 5623: DEBUG: pool_flush_it: flush size: 26
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: kind:S po:0
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 0 length: 41
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 1 length: 41
2020-08-31 08:38:22: pid 5623: DEBUG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: master slot: 2 length: 41
2020-08-31 08:38:22: pid 5623: DEBUG: pool_write: to frontend: length:4 po:1
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"session_authorization" value:"trnsx_services"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status

t-ishii

2020-08-31 16:05

developer   ~0003542

It seems server_version is different among the cluster:

2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:0 name:"server_version"
value:"10.10"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:1 name:"server_version"
value:"10.7"
2020-08-31 08:38:22: pid 5623: DEBUG: process parameter status
2020-08-31 08:38:22: pid 5623: DETAIL: backend:2 name:"server_version"
value:"10.7"

As you can see version of backend1 and 2 is 10.7, while backend0 is 10.10. It's better use identical PostgreSQL version, but probably it's ok in this case.
2020-08-31 08:38:22: pid 5623: LOG: reading message length
2020-08-31 08:38:22: pid 5623: DETAIL: message length (24) in slot 2 does not
match with slot 0(25)

2381917

2020-08-31 16:18

reporter   ~0003543

Thank you very much t-ishii.

Can you please let me know one more thing, is this error impacting any transaction ?

t-ishii

2020-08-31 16:29

developer   ~0003544

No, the message only appears while establishing connection to backend. Once the connection is established, it should not affect any transaction. However I recommend you to check there's any incompatibility between 10.7 and 10.10. Usually PostgreSQL is compatible with PostgreSQL which has same major version, but sometimes there is incompatibility between different minor versions. You'd better to check release notes closely.

2381917

2020-08-31 16:33

reporter   ~0003545

Thanks t-ishii.

You can close this ticket. I will try to make same postgres version on all nodes.

t-ishii

2020-08-31 17:06

developer   ~0003546

You are welcome. I'm going to close this ticket.

Issue History

Date Modified Username Field Change
2020-08-28 10:45 2381917 New Issue
2020-08-28 15:15 2381917 Note Added: 0003528
2020-08-29 11:32 t-ishii Assigned To => t-ishii
2020-08-29 11:32 t-ishii Status new => assigned
2020-08-29 11:40 t-ishii Note Added: 0003531
2020-08-29 11:50 t-ishii Status assigned => feedback
2020-08-30 00:31 2381917 File Added: pg_hba.conf
2020-08-30 00:31 2381917 File Added: pgpool.conf
2020-08-30 00:31 2381917 File Added: pool_hba.conf
2020-08-30 00:31 2381917 Note Added: 0003532
2020-08-30 00:31 2381917 Status feedback => assigned
2020-08-30 07:55 t-ishii Note Added: 0003533
2020-08-30 07:55 t-ishii Status assigned => feedback
2020-08-30 08:28 t-ishii Note Edited: 0003533
2020-08-31 14:17 2381917 Note Added: 0003539
2020-08-31 14:17 2381917 Status feedback => assigned
2020-08-31 14:30 t-ishii Note Added: 0003540
2020-08-31 14:30 t-ishii Status assigned => feedback
2020-08-31 14:50 2381917 Note Added: 0003541
2020-08-31 14:50 2381917 Status feedback => assigned
2020-08-31 16:05 t-ishii Note Added: 0003542
2020-08-31 16:05 t-ishii Status assigned => feedback
2020-08-31 16:18 2381917 Note Added: 0003543
2020-08-31 16:18 2381917 Status feedback => assigned
2020-08-31 16:29 t-ishii Note Added: 0003544
2020-08-31 16:29 t-ishii Status assigned => feedback
2020-08-31 16:33 2381917 Note Added: 0003545
2020-08-31 16:33 2381917 Status feedback => assigned
2020-08-31 17:06 t-ishii Note Added: 0003546
2020-08-31 17:07 t-ishii Status assigned => closed