Bug 1123935
| Summary: | node-proxy writes an invalid timestamp to logs when node is in UTC TZ | ||
|---|---|---|---|
| Product: | OpenShift Online | Reporter: | Jhon Honce <jhonce> |
| Component: | Containers | Assignee: | Rajat Chopra <rchopra> |
| Status: | CLOSED CURRENTRELEASE | QA Contact: | libra bugs <libra-bugs> |
| Severity: | medium | Docs Contact: | |
| Priority: | medium | ||
| Version: | 2.x | CC: | bmeng, jokerman, mmccomas, spinolacastro, yadu |
| Target Milestone: | --- | ||
| Target Release: | 2.x | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2014-10-10 00:49:49 UTC | Type: | Bug |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
Put in some debug messages to print memory information after each watchman plugin is invoked. The messages go in /var/log/messages and the debug mode can be enabled by setting an env var 'WATCHMAN_DEBUG' to true. Hopefully we can narrow it down which plugin causes the leak. https://github.com/openshift/origin-server/pull/5670 Wrong update in comment#1 above. Was meant for another bug. Pardon please. The better option would be to fix nodejs Logger, but until that is found.. an alternate proposal for fix in https://github.com/openshift/origin-server/pull/5671 Checked on devenv-stage_937, issue has been fixed.
With UTC timezone set on node. Comment out the 4 lines in oo-last-access script, I can get the error as:
[root@ip-10-179-182-124 ~]# oo-last-access
/usr/sbin/oo-last-access:117:in `strptime': invalid date (ArgumentError)
from /usr/sbin/oo-last-access:117:in `block (3 levels) in parse_log'
from /usr/sbin/oo-last-access:100:in `each'
from /usr/sbin/oo-last-access:100:in `block (2 levels) in parse_log'
from /usr/sbin/oo-last-access:99:in `popen'
from /usr/sbin/oo-last-access:99:in `block in parse_log'
from /usr/sbin/oo-last-access:98:in `each'
from /usr/sbin/oo-last-access:98:in `parse_log'
from /usr/sbin/oo-last-access:173:in `block in <main>'
from /usr/sbin/oo-last-access:155:in `call'
from /usr/sbin/oo-last-access:155:in `single_instance'
from /usr/sbin/oo-last-access:161:in `<main>'
With the fix patched:
[root@ip-10-179-182-124 ~]# oo-last-access
[root@ip-10-179-182-124 ~]#
Move bug to verified.
|
Description of problem: node-proxy writes an invalid timestamp to logs when node is in UTC TZ Version-Release number of selected component (if applicable): How reproducible: always Steps to Reproduce: 1. config node for UTC timezone 2. run oo-last-access 3. Actual results: /usr/sbin/oo-last-access:110:in `strptime': invalid date (ArgumentError) from /usr/sbin/oo-last-access:110:in `block (3 levels) in parse_log' from /usr/sbin/oo-last-access:99:in `each' from /usr/sbin/oo-last-access:99:in `block (2 levels) in parse_log' from /usr/sbin/oo-last-access:98:in `popen' from /usr/sbin/oo-last-access:98:in `block in parse_log' from /usr/sbin/oo-last-access:97:in `each' from /usr/sbin/oo-last-access:97:in `parse_log' from /usr/sbin/oo-last-access:167:in `block in <main>' from /usr/sbin/oo-last-access:149:in `call' from /usr/sbin/oo-last-access:149:in `single_instance' from /usr/sbin/oo-last-access:155:in `<main>' Expected results: Log is successfully parsed. Additional info: Note: Ruby expects a +- in front of TZ field. [root@node2 ~]# cat /var/log/node-web-proxy/websockets.log 179.98.105.155 meteor-caruccio.getup.io - - [25/Jul/2014:19:11:25 0000] "GET /sockjs/838/ad4l8fch/websocket HTTP/1.1" 1000 4005 "-" "Websocket RFC-6455/13" (822085ms) - 179.98.105.155 meteor-caruccio.getup.io - - [25/Jul/2014:21:28:15 0000] "GET /sockjs/132/4quo29hi/websocket HTTP/1.1" 1000 5421 "-" "Websocket RFC-6455/13" (1046406ms) - 179.98.105.155 meteor-caruccio.getup.io - - [25/Jul/2014:22:38:57 0000] "GET /sockjs/428/o6tzauwl/websocket HTTP/1.1" 1000 1156 "-" "Websocket RFC-6455/13" (75346ms) - 179.98.105.155 meteor-caruccio.getup.io - - [26/Jul/2014:22:02:53 0000] "GET /sockjs/780/pvifap4p/websocket HTTP/1.1" 1000 1104 "-" "Websocket RFC-6455/13" (3375ms) -