11<?php
2+
23namespace Webman \Log ;
34
5+ use Illuminate \Container \Container ;
6+ use Illuminate \Database \Connection ;
7+ use Illuminate \Database \Events \QueryExecuted ;
8+ use Illuminate \Events \Dispatcher ;
9+ use Illuminate \Redis \Events \CommandExecuted ;
410use support \Db ;
511use support \Log ;
612use support \Redis ;
713use think \db \connector \Mysql ;
814use think \facade \Db as ThinkDb ;
15+ use Throwable ;
916use Webman \Http \Request ;
1017use Webman \Http \Response ;
1118use Webman \MiddlewareInterface ;
12- use Illuminate \Database \Connection ;
13- use Illuminate \Database \Events \QueryExecuted ;
14- use Illuminate \Redis \Events \CommandExecuted ;
15- use Throwable ;
19+ use RuntimeException ;
1620
1721class Middleware implements MiddlewareInterface
1822{
@@ -26,69 +30,38 @@ class Middleware implements MiddlewareInterface
2630 * @param callable $next
2731 * @return Response
2832 */
29- public function process (Request $ request , callable $ next ) : Response
33+ public function process (Request $ request , callable $ next ): Response
3034 {
31- static $ initialized_db , $ initialized_redis ;
35+ static $ initialized_db ;
36+
37+ // 请求开始时间
3238 $ start_time = microtime (true );
39+
40+ // 记录ip 请求等信息
3341 $ logs = $ request ->getRealIp () . ' ' . $ request ->method () . ' ' . trim ($ request ->fullUrl (), '/ ' );
3442 $ this ->logs = '' ;
43+
44+ // 清理think-orm的日志
3545 if (class_exists (ThinkDb::class, false ) && class_exists (Mysql::class, false )) {
3646 ThinkDb::getDbLog (true );
3747 }
48+
49+ // 初始化数据库监听
3850 if (!$ initialized_db ) {
3951 $ initialized_db = true ;
40- if (class_exists (QueryExecuted::class)) {
41- try {
42- Db::listen (function (QueryExecuted $ query ) {
43- $ sql = trim ($ query ->sql );
44- if (strtolower ($ sql ) === 'select 1 ' ) {
45- return ;
46- }
47- $ sql = str_replace ("? " , "%s " , $ sql );
48- foreach ($ query ->bindings as $ i => $ binding ) {
49- if ($ binding instanceof \DateTime) {
50- $ query ->bindings [$ i ] = $ binding ->format ("'Y-m-d H:i:s' " );
51- } else {
52- if (is_string ($ binding )) {
53- $ query ->bindings [$ i ] = "' $ binding' " ;
54- }
55- }
56- }
57- $ log = vsprintf ($ sql , $ query ->bindings );
58- $ this ->logs .= "[SQL] \t[connection: {$ query ->connectionName }] $ log [ {$ query ->time } ms] " . PHP_EOL ;
59- });
60- } catch (\Throwable $ e ) {echo $ e ;}
61- }
52+ $ this ->initDbListen ();
6253 }
6354
64- if (!$ initialized_redis ) {
65- $ initialized_redis = true ;
66- if (class_exists (CommandExecuted::class)) {
67- foreach (config ('redis ' , []) as $ key => $ config ) {
68- if (strpos ($ key , 'redis-queue ' ) !== false ) {
69- continue ;
70- }
71- try {
72- Redis::connection ($ key )->listen (function (CommandExecuted $ command ) {
73- foreach ($ command ->parameters as &$ item ) {
74- if (is_array ($ item )) {
75- $ item = implode ('\', \'' , $ item );
76- }
77- }
78- $ this ->logs .= "[Redis] \t[connection: {$ command ->connectionName }] Redis:: {$ command ->command }(' " . implode ('\', \'' , $ command ->parameters ) . "') ( {$ command ->time } ms) " . PHP_EOL ;
79- });
80- } catch (\Throwable $ e ) {}
81- }
82- }
83- }
55+ // 得到响应
8456 $ response = $ next ($ request );
85- $ time_diff = substr ((microtime (true ) - $ start_time )* 1000 , 0 , 7 );
57+ $ time_diff = substr ((microtime (true ) - $ start_time ) * 1000 , 0 , 7 );
8658 $ logs .= " [ {$ time_diff }ms] [webman/log] " . PHP_EOL ;
8759 if ($ request ->method () === 'POST ' ) {
8860 $ logs .= "[POST] \t" . var_export ($ request ->post (), true ) . PHP_EOL ;
8961 }
9062 $ logs .= $ this ->logs ;
9163
64+ // think-orm如果被使用,则记录think-orm的日志
9265 if ($ loaded_think_db = (class_exists (ThinkDb::class, false ) && class_exists (Mysql::class, false ))) {
9366 $ sql_logs = ThinkDb::getDbLog (true );
9467 if (!empty ($ sql_logs ['sql ' ])) {
@@ -98,45 +71,206 @@ public function process(Request $request, callable $next) : Response
9871 }
9972 }
10073
74+ // 判断业务是否出现异常
10175 $ exception = null ;
10276 if (method_exists ($ response , 'exception ' )) {
10377 $ exception = $ response ->exception ();
10478 }
10579
80+ // 尝试记录异常
10681 $ method = 'info ' ;
107-
10882 if ($ exception && config ('plugin.webman.log.app.exception.enable ' , true ) && !$ this ->shouldntReport ($ exception )) {
10983 $ logs .= $ exception . PHP_EOL ;
11084 $ method = 'error ' ;
11185 }
11286
87+ // 判断Db是否有未提交的事务
88+ $ has_uncommited_transaction = false ;
11389 if (class_exists (Connection::class, false )) {
114- $ pdo = Db::getPdo ();
115- if ($ pdo && $ pdo ->inTransaction ()) {
116- Db::rollBack ();
90+ if ($ log = $ this ->checkDbUncommitTransaction ()) {
91+ $ has_uncommited_transaction = true ;
11792 $ method = 'error ' ;
118- $ logs .= " [ERROR] \t Uncommitted transactions and rollback " . PHP_EOL ;
93+ $ logs .= $ log ;
11994 }
12095 }
96+
97+ // 判断think-orm是否有未提交的事务
12198 if ($ loaded_think_db ) {
122- $ pdo = ThinkDb::getPdo ();
123- if ($ pdo && $ pdo ->inTransaction ()) {
124- Db::rollBack ();
99+ if ($ log = $ this ->checkTpUncommitTransaction ()) {
100+ $ has_uncommited_transaction = true ;
125101 $ method = 'error ' ;
126- $ logs .= " [ERROR] \t Uncommitted transactions and rollback " . PHP_EOL ;
102+ $ logs .= $ log ;
127103 }
128104 }
129105
106+ /**
107+ * 初始化redis监听
108+ * 注意:由于redis是延迟监听,所以第一个请求不会记录redis具体日志
109+ */
110+ $ new_names = $ this ->tryInitRedisListen ();
111+ foreach ($ new_names as $ name ) {
112+ $ logs .= "[Redis] \t[connection: {$ name }] ... " . PHP_EOL ;
113+ }
114+
130115 call_user_func ([Log::class, $ method ], $ logs );
131116
117+ if ($ has_uncommited_transaction ) {
118+ throw new RuntimeException ('Uncommitted transactions found ' );
119+ }
120+
132121 return $ response ;
133122 }
134123
135124 /**
125+ * 初始化数据库日志监听
126+ *
127+ * @return void
128+ */
129+ protected function initDbListen ()
130+ {
131+ if (!class_exists (QueryExecuted::class)) {
132+ return ;
133+ }
134+ try {
135+ $ capsule = $ this ->getCapsule ();
136+ $ dispatcher = new Dispatcher (new Container );
137+ $ dispatcher ->listen (QueryExecuted::class, function (QueryExecuted $ query ) {
138+ $ sql = trim ($ query ->sql );
139+ if (strtolower ($ sql ) === 'select 1 ' ) {
140+ return ;
141+ }
142+ $ sql = str_replace ("? " , "%s " , $ sql );
143+ foreach ($ query ->bindings as $ i => $ binding ) {
144+ if ($ binding instanceof \DateTime) {
145+ $ query ->bindings [$ i ] = $ binding ->format ("'Y-m-d H:i:s' " );
146+ } else {
147+ if (is_string ($ binding )) {
148+ $ query ->bindings [$ i ] = "' $ binding' " ;
149+ }
150+ }
151+ }
152+ $ log = vsprintf ($ sql , $ query ->bindings );
153+ $ this ->logs .= "[SQL] \t[connection: {$ query ->connectionName }] $ log [ {$ query ->time } ms] " . PHP_EOL ;
154+ });
155+ $ capsule ->setEventDispatcher ($ dispatcher );
156+ } catch (\Throwable $ e ) {
157+ echo $ e ;
158+ }
159+ }
160+
161+ /**
162+ * 尝试初始化redis日志监听
163+ *
164+ * @return void
165+ */
166+ protected function tryInitRedisListen ()
167+ {
168+ static $ listened_names = [];
169+ if (!class_exists (CommandExecuted::class)) {
170+ return [];
171+ }
172+ $ new_names = [];
173+ foreach (Redis::instance ()->connections () ?: [] as $ connection ) {
174+ /* @var \Illuminate\Redis\Connections\Connection $connection */
175+ $ name = $ connection ->getName ();
176+ if (isset ($ listened_names [$ name ])) {
177+ continue ;
178+ }
179+ $ connection ->listen (function (CommandExecuted $ command ) {
180+ foreach ($ command ->parameters as &$ item ) {
181+ if (is_array ($ item )) {
182+ $ item = implode ('\', \'' , $ item );
183+ }
184+ }
185+ $ this ->logs .= "[Redis] \t[connection: {$ command ->connectionName }] Redis:: {$ command ->command }(' " . implode ('\', \'' , $ command ->parameters ) . "') ( {$ command ->time } ms) " . PHP_EOL ;
186+ });
187+ $ listened_names [$ name ] = $ name ;
188+ $ new_names [] = $ name ;
189+ }
190+ return $ new_names ;
191+ }
192+
193+
194+ /**
195+ * 获得Db的Manager
196+ *
197+ * @return mixed
198+ */
199+ protected function getCapsule ()
200+ {
201+ static $ capsule ;
202+ if (!$ capsule ) {
203+ $ reflect = new \ReflectionClass (Db::class);
204+ $ property = $ reflect ->getProperty ('instance ' );
205+ $ property ->setAccessible (true );
206+ $ capsule = $ property ->getValue ();
207+ }
208+ return $ capsule ;
209+ }
210+
211+ /**
212+ * 检查Db是否有未提交的事务
213+ *
214+ * @return string
215+ * @throws Throwable
216+ */
217+ protected function checkDbUncommitTransaction ()
218+ {
219+ $ logs = '' ;
220+ foreach ($ this ->getCapsule ()->getDatabaseManager ()->getConnections () as $ connection ) {
221+ /* @var \Illuminate\Database\MySqlConnection $connection * */
222+ if (\in_array ($ connection ->getConfig ('driver ' ), ['mysql ' , 'pgsql ' , 'sqlite ' , 'sqlsrv ' ])) {
223+ $ pdo = $ connection ->getPdo ();
224+ if ($ pdo && $ pdo ->inTransaction ()) {
225+ $ connection ->rollBack ();
226+ $ method = 'error ' ;
227+ $ logs .= "[ERROR] \tUncommitted transaction found and try to rollback " . PHP_EOL ;
228+ }
229+ }
230+ }
231+ return $ logs ;
232+ }
233+
234+ /**
235+ * 检查think-orm是否有未提交的事务
236+ *
237+ * @return string
238+ * @throws \ReflectionException
239+ */
240+ protected function checkTpUncommitTransaction ()
241+ {
242+ static $ reflect , $ instance ;
243+ if (!$ reflect ) {
244+ $ reflect = new \ReflectionClass (\think \facade \Db::class);
245+ $ property = $ reflect ->getProperty ('instance ' );
246+ $ property ->setAccessible (true );
247+ $ instance = $ property ->getValue ();
248+ $ reflect = new \ReflectionClass ($ property ->getValue ());
249+ }
250+ $ property = $ reflect ->getProperty ('instance ' );
251+ $ property ->setAccessible (true );
252+ $ instances = $ property ->getValue ($ instance );
253+ $ logs = '' ;
254+ foreach ($ instances as $ connection ) {
255+ /* @var \think\db\connector\Mysql $connection */
256+ $ pdo = $ connection ->getPdo ();
257+ if ($ pdo && $ pdo ->inTransaction ()) {
258+ $ connection ->rollBack ();
259+ $ method = 'error ' ;
260+ $ logs .= "[ERROR] \tUncommitted transaction found and try to rollback " . PHP_EOL ;
261+ }
262+ }
263+ return $ logs ;
264+ }
265+
266+ /**
267+ * 判断是否需要记录异常
268+ *
136269 * @param Throwable $e
137270 * @return bool
138271 */
139- protected function shouldntReport ($ e ) {
272+ protected function shouldntReport ($ e )
273+ {
140274 foreach (config ('plugin.webman.log.app.exception.dontReport ' , []) as $ type ) {
141275 if ($ e instanceof $ type ) {
142276 return true ;
0 commit comments