Greenplum數據庫中日志實例分析

這篇文章主要介紹“Greenplum數據庫中日志實例分析”，在日常操作中，相信很多人在Greenplum數據庫中日志實例分析問題上存在疑惑，小編查閱了各式資料，整理出簡單好用的操作方法，希望對大家解答”Greenplum數據庫中日志實例分析”的疑惑有所幫助！接下來，請跟著小編一起來學習吧！

Greenplum通過Master接受外部增刪改查操作，默認情況下，所有增刪改查操作都會記錄到$MASTER_DATA_DIRECTORY/pg_log下對應的文件中。

1.有時候查看Greenplum Master日志的時候，會發現有一些LOG信息類似如下：

2020-09-09 20:09:56.760795 CST,"gposs5","postgres",p32314,th-591984576,"10.211.55.2","61196",2020-09-09 20:09:56 CST,0,con10,cmd1,seg-1,,dx4,,sx1,"LOG","00000","statement: BEGIN",,,,,,"BEGIN",0,,"postgres.c",1590,
2020-09-09 20:09:56.769845 CST,"gposs5","postgres",p32314,th-591984576,"10.211.55.2","61196",2020-09-09 20:09:56 CST,0,con10,cmd2,seg-1,,dx4,,sx1,"LOG","00000","statement: select 2020-09-08",,,,,,"select 2020-09-08",0,,"postgres.c",1590,
2020-09-09 20:09:56.771312 CST,"gposs5","postgres",p32314,th-591984576,"10.211.55.2","61196",2020-09-09 20:09:56 CST,0,con11,,seg-1,,dx4,,sx1,"LOG","00000","The previous session was reset because its gang was disconnected (session id = 10). The new session id = 11",,,,,,,0,,"cdbgang.c",1710,

那么這些日志為何會產生呢？下面我們通過一段簡單的python代碼來復現幾個場景。

2.代碼部分如下：

update1_sql = "select %s"
conn1 = Tools.gp_connect()
cur1 = conn1.cursor()
cur1.execute(update1_sql % "'2020-09-08'")
row = cur1.fetchone()
cur1.close()
print(row[0])
conn1.commit()
conn1.close()

time.sleep(1000000)

此段代碼為正常執行的代碼，后臺數據庫產生的日志如下，有begin;正常執行查詢語句;commit;  

2020-09-09 20:30:30.898275 CST,"gposs5","postgres",p4116,th-591984576,"10.211.55.2","64416",2020-09-09 20:30:30 CST,0,con41,cmd1,seg-1,,dx26,,sx1,"LOG","00000","statement: BEGIN",,,,,,"BEGIN",0,,"postgres.c",1590,
2020-09-09 20:30:30.909131 CST,"gposs5","postgres",p4116,th-591984576,"10.211.55.2","64416",2020-09-09 20:30:30 CST,0,con41,cmd2,seg-1,,dx26,,sx1,"LOG","00000","statement: select '2020-09-08'",,,,,,"select '2020-09-08'",0,,"postgres.c",1590,
2020-09-09 20:30:30.909766 CST,"gposs5","postgres",p4116,th-591984576,"10.211.55.2","64416",2020-09-09 20:30:30 CST,0,con41,cmd4,seg-1,,dx26,,sx1,"LOG","00000","statement: COMMIT",,,,,,"COMMIT",0,,"postgres.c",1590,

錯誤場景一：

我們把代碼中的commit部分注釋掉，如下：

update1_sql = "select %s"
conn1 = Tools.gp_connect()
cur1 = conn1.cursor()
cur1.execute(update1_sql % "'2020-09-08'")
row = cur1.fetchone()
cur1.close()
print(row[0])
#conn1.commit()
conn1.close()

time.sleep(1000000)

執行上面代碼，可以正常獲取查詢結果，但是實際上我們開啟事務后并沒有正常關閉，然后就直接把數據庫連接關了，有點粗暴啊。此時，數據庫日志如下：

2020-09-09 20:34:31.100551 CST,"gposs5","postgres",p4869,th-591984576,"10.211.55.2","65043",2020-09-09 20:34:31 CST,0,con42,cmd1,seg-1,,dx27,,sx1,"LOG","00000","statement: BEGIN",,,,,,"BEGIN",0,,"postgres.c",1590,
2020-09-09 20:34:31.116187 CST,"gposs5","postgres",p4869,th-591984576,"10.211.55.2","65043",2020-09-09 20:34:31 CST,0,con42,cmd2,seg-1,,dx27,,sx1,"LOG","00000","statement: select '2020-09-08'",,,,,,"select '2020-09-08'",0,,"postgres.c",1590,
2020-09-09 20:34:31.117199 CST,"gposs5","postgres",p4869,th-591984576,"10.211.55.2","65043",2020-09-09 20:34:31 CST,0,con43,,seg-1,,dx27,,sx1,"LOG","00000","The previous session was reset because its gang was disconnected (session id = 42). The new session id = 43",,,,,,,0,,"cdbgang.c",1710,

The previous session was reset because its gang was disconnected，數據庫重置了該會話。

錯誤場景二：

我們把代碼中的commit部分放開，把連接close的代碼注釋掉：

update1_sql = "select %s"
conn1 = Tools.gp_connect()
cur1 = conn1.cursor()
cur1.execute(update1_sql % "'2020-09-08'")
row = cur1.fetchone()
cur1.close()
print(row[0])
conn1.commit()
# conn1.close()

time.sleep(1000000)

此時是一個完整的事務，只是說我們沒有把該連接關掉，還可以在該代碼中執行一些其他的操作，但是最終，這個鏈接是一定要關掉的，否則會耗盡數據庫資源：

2020-09-09 20:38:43.982689 CST,"gposs5","postgres",p5655,th-591984576,"10.211.55.2","49315",2020-09-09 20:38:43 CST,0,con44,cmd1,seg-1,,dx28,,sx1,"LOG","00000","statement: BEGIN",,,,,,"BEGIN",0,,"postgres.c",1590,
2020-09-09 20:38:43.996448 CST,"gposs5","postgres",p5655,th-591984576,"10.211.55.2","49315",2020-09-09 20:38:43 CST,0,con44,cmd2,seg-1,,dx28,,sx1,"LOG","00000","statement: select '2020-09-08'",,,,,,"select '2020-09-08'",0,,"postgres.c",1590,
2020-09-09 20:38:43.996787 CST,"gposs5","postgres",p5655,th-591984576,"10.211.55.2","49315",2020-09-09 20:38:43 CST,0,con44,cmd4,seg-1,,dx28,,sx1,"LOG","00000","statement: COMMIT",,,,,,"COMMIT",0,,"postgres.c",1590,

錯誤場景三：

這個場景比較有意思，也是最值得我們注意的一個錯誤場景，如下，我們把commit和close操作都注釋掉：

update1_sql = "select %s"
conn1 = Tools.gp_connect()
cur1 = conn1.cursor()
cur1.execute(update1_sql % "'2020-09-08'")
row = cur1.fetchone()
cur1.close()
print(row[0])
# conn1.commit()
# conn1.close()

time.sleep(1000000)

此時，該代碼也能正常執行，控制臺也有正確的結果返回。后臺數據庫日志如下，只有begin和sql查詢，沒有對應的commit語句。

2020-09-09 20:42:15.271391 CST,"gposs5","postgres",p6347,th-591984576,"10.211.55.2","49861",2020-09-09 20:42:15 CST,0,con47,cmd1,seg-1,,dx32,,sx1,"LOG","00000","statement: BEGIN",,,,,,"BEGIN",0,,"postgres.c",1590,
2020-09-09 20:42:15.284936 CST,"gposs5","postgres",p6347,th-591984576,"10.211.55.2","49861",2020-09-09 20:42:15 CST,0,con47,cmd2,seg-1,,dx32,,sx1,"LOG","00000","statement: select '2020-09-08'",,,,,,"select '2020-09-08'",0,,"postgres.c",1590,

此時我們查詢活動視圖，發現該事務沒有正常關閉：

postgres=# select * from pg_stat_activity;
 datid | datname  | procpid | sess_id | usesysid | usename |          current_query          | waiting |          query_start          |         backend_start
   | client_addr | client_port | application_name |          xact_start           | waiting_reason | rsgid | rsgname | rsgqueueduration
-------+----------+---------+---------+----------+---------+---------------------------------+---------+-------------------------------+----------------------------
---+-------------+-------------+------------------+-------------------------------+----------------+-------+---------+------------------
 12094 | postgres |    6347 |      47 |       10 | gposs5  | <IDLE> in transaction           | f       | 2020-09-09 20:42:15.284855+08 | 2020-09-09 20:42:15.268696+
08 | 10.211.55.2 |       49861 |                  | 2020-09-09 20:42:15.271253+08 |                |     0 | unknown |
 12094 | postgres |    3096 |      25 |       10 | gposs5  | select * from pg_stat_activity; | f       | 2020-09-09 20:45:39.149973+08 | 2020-09-09 20:25:17.0897+08
   |             |          -1 | psql             | 2020-09-09 20:45:39.149973+08 |                |     0 | unknown |
(2 rows)

那么這個場景就有意思了，如果你不提交，也不關閉連接，此時只能聽天由命了，萬一來一個DDL語句，馬上就會鎖表，所有DDL后面的查詢都會等待鎖而處于假死狀態。

從上面的幾個例子可以看到，在python里面，如果沒有顯示的提交，便會產生上面的一些提示日志，這種情況，可以擴展到任何將查詢作為一個單獨事務的語言或框架中，這就要求我們在平時代碼編寫時，養成良好的數據庫提交習慣。

備注：以上問題是在gpdb5.x上面復現的，在5.x的較新版本及6.x中，存在一個idle in transaction處理參數，用于在數據庫層面上處理這種未正常結束的事務。無論怎樣，最好的處理方式還是正確的使用代碼來訪問數據庫。

到此，關于“Greenplum數據庫中日志實例分析”的學習就結束了，希望能夠解決大家的疑惑。理論與實踐的搭配能更好的幫助大家學習，快去試試吧！若想繼續學習更多相關知識，請繼續關注億速云網站，小編會繼續努力為大家帶來更多實用的文章！