按请求登录Node.js [英] Per request logging in Node.js
问题描述
我是一位经验丰富的Java开发人员，他们选择Node.js并转向异步模型。除了伐木以外，大多数事情都很顺利。在使用express的Node.js中进行开发时，我在Java中找不到类似于log4j和NDCs的任何内容。
I am an experienced Java developer picking up Node.js and making the shift to the asynchronous model. Most things are going fine except for logging. I cannot find anything similar to log4j and NDCs in Java while developing in Node.js with express.
我的目标是让每个日志语句自动添加以下信息：
My goal is to have each log statement automatically prepend the following information:
[2013-11-07 11：17：04.615 serverScript INFO 7036 192.168.7.209]
[2013-11-07 11:17:04.615 serverScript INFO 7036 192.168.7.209]
这包括timestamp，写入此语句的js文件的名称（对于模块化节点应用程序），调试级别，进程ID（运行集群）和客户端的IP地址。
This includes the timestamp, name of the js file writing this statement (for modularized node apps), the debug level, the process ID (running clusters), and the client's IP address.
我可以在最初进入我的请求处理程序时写它们，但是如果没有将一堆参数传播到每个被调用的函数，子例程中的记录器语句就没有信息。我知道我可以在每个初始化其名称的js文件中创建我的记录器实例，但我还没有找到客户端IP地址的解决方案。对于运行时间较长的请求，我在记录器中设置的地址会在下一个请求进入时被覆盖，因此记录的IP会被越过。
I can get it to write these when initially coming into my request handler, but without propagating a bunch of parameters to every called function, the logger statements inside the subroutines don't have the info. I know I can create an instance of my logger inside each js file that initializes its name, but I've yet to figure out a solution for the IP address of the client. For longer running requests, the address I set in my logger gets overwritten when the next request comes in, so the IPs that are logged get crossed.
我看过温斯顿但即使用它也无法解决这个问题。有没有人完成这个？当您可以通过IP过滤以仅查看一个用户的活动时，这是非常有用的跟踪字段问题。
I've looked at winston but have not been able to solve this issue even with it. Has anyone accomplished this? It is very useful tracking field issues when you can filter by IP to view only one user's activity.
[2013-11-07 14:29:28.641 server INFO 7527 192.168.7.209] Got request from 192.168.7.209 for /ionmed/executeQuery?
[2013-11-07 14:29:28.641 router INFO 7527 192.168.7.209] About to route a request for /ionmed/executeQuery, method=POST
[2013-11-07 14:29:28.642 router INFO 7527 192.168.7.209] getting POSTed data
[2013-11-07 14:29:28.642 router INFO 7527 192.168.7.209] POST params: {"sqlQuery":"select sleep(10)","sessionStart":"1383852558799","rand":"0.5510970998368581","jsessionid":"117DBAA89F599D923AF80D4AB171BDDF"}
[2013-11-07 14:29:28.642 requestHandlers INFO 7527 192.168.7.209] 'query' was called.
[2013-11-07 14:29:28.642 requestHandlers INFO 7527 192.168.7.209] select sleep(10)
[2013-11-07 14:29:30.673 server INFO 7527 192.168.7.217] Got request from 192.168.7.217 for /
[2013-11-07 14:29:30.673 router INFO 7527 192.168.7.217] About to route a request for /, method=GET
[2013-11-07 14:29:30.673 router INFO 7527 192.168.7.217] No request handler found for /; serving as file
[2013-11-07 14:29:30.673 router INFO 7527 192.168.7.217] Request handler 'serveFile' was called to get: /index.html
[192.168.7.217 Thu, 07 Nov 2013 19:29:30 GMT] HTTP/1.1 GET "/node/" 200 "Mozilla/5.0 (iPod; CPU iPhone OS 5_1_1 like Mac OS X) AppleWebKit/534.46 (KHTML, like Gecko) Version/5.1 Mobile/9B206 Safari/7534.48.3"
[2013-11-07 14:29:33.578 server INFO 7527 192.168.7.217] Got request from 192.168.7.217 for /
[2013-11-07 14:29:33.578 router INFO 7527 192.168.7.217] About to route a request for /, method=GET
[2013-11-07 14:29:33.578 router INFO 7527 192.168.7.217] No request handler found for /; serving as file
[2013-11-07 14:29:33.579 router INFO 7527 192.168.7.217] Request handler 'serveFile' was called to get: /index.html
[192.168.7.217 Thu, 07 Nov 2013 19:29:33 GMT] HTTP/1.1 GET "/node/" 200 "Mozilla/5.0 (iPod; CPU iPhone OS 5_1_1 like Mac OS X) AppleWebKit/534.46 (KHTML, like Gecko) Version/5.1 Mobile/9B206 Safari/7534.48.3"
[2013-11-07 14:29:38.644 requestHandlers INFO 7527 192.168.7.209] sending response
[192.168.7.209 Thu, 07 Nov 2013 19:29:38 GMT] HTTP/1.1 POST "/node/ionmed/executeQuery?" 200 "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:25.0) Gecko/20100101 Firefox/25.0"
[2013-11-07 14:29:41.540 server INFO 7527 192.168.7.217] Got request from 192.168.7.217 for /
[2013-11-07 14:29:41.541 router INFO 7527 192.168.7.217] About to route a request for /, method=GET
[2013-11-07 14:29:41.541 router INFO 7527 192.168.7.217] No request handler found for /; serving as file
[2013-11-07 14:29:41.541 router INFO 7527 192.168.7.217] Request handler 'serveFile' was called to get: /index.html
[192.168.7.217 Thu, 07 Nov 2013 19:29:41 GMT] HTTP/1.1 GET "/node/" 200 "Mozilla/5.0 (iPod; CPU iPhone OS 5_1_1 like Mac OS X) AppleWebKit/534.46 (KHTML, like Gecko) Version/5.1 Mobile/9B206 Safari/7534.48.3"
[2013-11-07 14:29:45.146 server INFO 7527 192.168.7.209] RLz6tmJ7KTH2R16VCVTX: bye {"user":"1"}
[2013-11-07 14:29:45.176 server INFO 7527 192.168.7.209] RLz6tmJ7KTH2R16VCVTX: disconnected
现在我只需要计算如何使快速请求记录器与我的内部记录器具有相同的行条目格式，直到它全部移动到rsyslog。
Now I just need to figure out how to get the express request logger to be in the same line entry format as my internal logger until it is all moved to rsyslog.
推荐答案
前段时间我遇到了同样的问题，最后我可以花一些时间来研究它。 @ibash方法和他的帖子让我领先解决我遇到的问题（感谢您的帮助）。我只走了一些步骤，以便在日志中自动打印每个请求的唯一ID。
在您的情况下，您可以使用相同的方法添加原始和目标IP以及每个请求所需的所有信息，并在所有日志中自动打印。
I got into this same problem some time ago, and finally I could spend sometime researching it. The @ibash approach and his post put me in the lead to solve the problem I had (thanks for your help). I only walked some steps more in order to print in the logs automatically a unique id per request. In your case you can add origin and destination IP and all information needed to each request, using same approach and print it automatically in all logs.
我的方法：
- 正如@ibash解释的那样，我使用continuation-local-storage在每个请求的所有模块之间共享信息。所以我为每个请求生成一个唯一的id并将它存储在用这个库创建的命名空间中
- 我包装了Winston库（以一种非常简单的方式），以便从共享的命名空间中恢复信息并覆盖所有Winston方法我使用添加到字符串的唯一ID。显然，在您的情况下，您应该添加所需的所有信息，并且之前已存储在库的命名空间中。
My approach: - As @ibash explained, I used continuation-local-storage to share information among all the modules per request. So I generate a unique id per request and store it in a namespace created with this library - I wrapped the Winston library (in a very simple way) in order to recover the information from the namespace shared and override all Winston methods I use adding to the string the unique Id. Obviously in your case you should add all the info you need and you have stored previously in the namespace of the library.
因为问题有点复杂，无法向人们解释不熟悉所有这些事情，我在一篇文章中写下了一个明确的例子，如果你愿意，你可以重复使用。 Winston wrap非常有用：
Express.js：Logging带有全局唯一请求ID的信息 - Node.js
As the problem was a little complex to explain to people no familiarize with all these things, I wrote it down in a post with a clear example that you can reuse if you want. Winston wrap could be really useful: Express.js: Logging info with global unique request ID – Node.js
我希望您可以重用我的代码，也许将来Express会为此实现解决方案。
I hope you can reuse my code and perhaps in the future Express implements a solution for this.
这篇关于按请求登录Node.js的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！
