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) -
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.