Return-Path: X-Original-To: apmail-cassandra-commits-archive@www.apache.org Delivered-To: apmail-cassandra-commits-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id DA2F79E94 for ; Mon, 30 Jan 2012 19:16:58 +0000 (UTC) Received: (qmail 51938 invoked by uid 500); 30 Jan 2012 19:16:58 -0000 Delivered-To: apmail-cassandra-commits-archive@cassandra.apache.org Received: (qmail 51907 invoked by uid 500); 30 Jan 2012 19:16:58 -0000 Mailing-List: contact commits-help@cassandra.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cassandra.apache.org Delivered-To: mailing list commits@cassandra.apache.org Delivered-To: moderator for commits@cassandra.apache.org Received: (qmail 36353 invoked by uid 99); 30 Jan 2012 19:07:49 -0000 X-ASF-Spam-Status: No, hits=-0.7 required=5.0 tests=RCVD_IN_DNSWL_LOW,SPF_PASS,SUBJ_OBFU_PUNCT_FEW X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: domain of 3auomTyAMAFk31JJ1E4I1-EF45.1G1385-5OKI1J.FI73F45JGFK.3FD@codesite.bounces.google.com designates 209.85.210.76 as permitted sender) MIME-Version: 1.0 X-Generated-By: Google Code Message-ID: <047d7b2ed949612ebb04b7c38ea7@google.com> Date: Mon, 30 Jan 2012 19:07:22 +0000 Subject: [cassandra-node] 2 new revisions pushed by gdusbabek@gmail.com on 2012-01-30 19:06 GMT From: cassandra-node.apache-extras.org@codespot.com To: commits@cassandra.apache.org Content-Type: text/plain; charset=ISO-8859-1; format=flowed; delsp=yes X-Virus-Checked: Checked by ClamAV on apache.org 2 new revisions: Revision: 9888be187a23 Author: Christoph Tavan Date: Thu Jan 26 14:40:08 2012 Log: Emit log events and remove logmagic dependency http://code.google.com/a/apache-extras.org/p/cassandra-node/source/detail?r=9888be187a23 Revision: 764dd54a7bc3 Author: Gary Dusbabek Date: Mon Jan 30 10:26:55 2012 Log: Merge commit '9888be187a23a2a2b5ca8a01e7710b7e48f9f00c' into 16/remove... http://code.google.com/a/apache-extras.org/p/cassandra-node/source/detail?r=764dd54a7bc3 ============================================================================== Revision: 9888be187a23 Author: Christoph Tavan Date: Thu Jan 26 14:40:08 2012 Log: Emit log events and remove logmagic dependency http://code.google.com/a/apache-extras.org/p/cassandra-node/source/detail?r=9888be187a23 Modified: /README.md /lib/driver.js /lib/system.js /package.json /test/test_driver.js ======================================= --- /README.md Fri Dec 2 13:23:47 2011 +++ /README.md Thu Jan 26 14:40:08 2012 @@ -130,6 +130,17 @@ // Shutting down a pool connection_pool.shutdown(function() { console.log("connection pool shutdown"); }); +### Logging +Instances of `Connection()` and `PooledConnection()` are `EventEmitter`'s and emit `log` events: + + var Connection = require('node-cassandra-client').Connection; + var con = new Connection({host:'cassandra-host', port:9160, keyspace:'Keyspace1', user:'user', pass:'password'}); + con.on('log', function(level, message) { + console.log('log event: %s -- %j', level, message); + }); + +The `level` being passed to the listener can be one of `debug`, `info`, `warn`, `error`, `timing` and `cql`. The `message` is usually a string, in the case of `timing` and `cql` it is an object that provides more detailed information. + Things you should know about ============================ ======================================= --- /lib/driver.js Mon Jan 23 11:22:55 2012 +++ /lib/driver.js Thu Jan 26 14:40:08 2012 @@ -17,10 +17,6 @@ /** node.js driver for Cassandra-CQL. */ -var log = require('logmagic').local('node-cassandra-client.driver'); -var logCql = require('logmagic').local('node-cassandra-client.driver.cql'); -var logTiming = require('logmagic').local('node-cassandra-client.driver.timing'); - var util = require('util'); var constants = require('constants'); var Buffer = require('buffer').Buffer; @@ -187,12 +183,14 @@ */ var Connection = module.exports.Connection = function(options) { options = options || {}; - log.info('connecting ' + options.host + ':' + options.port); this.validators = {}; this.client = null; this.connectionInfo = options; this.timeout = options.timeout || DEFAULT_CONNECTION_TIMEOUT; + + EventEmitter.call(this); }; +util.inherits(Connection, EventEmitter); /** @@ -203,6 +201,8 @@ var self = this, timeoutId; + self.emit('log', 'info', 'connecting ' + self.connectionInfo.host + ':' + self.connectionInfo.port); + // build connection here, so that timeouts on bad hosts happen now and not in the constructor. this.con = thrift.createConnection(self.connectionInfo.host, self.connectionInfo.port); this.con.on('error', function(err) { @@ -213,7 +213,7 @@ this.con.on('close', function() { clearTimeout(timeoutId); - log.info(self.connectionInfo.host + ':' + self.connectionInfo.port + ' is closed'); + self.emit('log', 'info', self.connectionInfo.host + ':' + self.connectionInfo.port + ' is closed'); }); this.con.on('connect', function() { @@ -357,7 +357,7 @@ start, end, diff; start = new Date().getTime(); - logCql.trace('CQL QUERY', {'query': query, 'parameterized_query': cqlString, 'args': args}); + self.emit('log', 'cql', {'query': query, 'parameterized_query': cqlString, 'args': args}); // if a connection dies at the right place, execute_cql_query never returns. make sure the callback gets called. var timeoutId = setTimeout(function() { @@ -366,7 +366,7 @@ }, this.timeout); // todo: should we disambiguate connection timeout vs query timeout? self.client.execute_cql_query(cql, ttypes.Compression.NONE, function(err, res) { if (!timeoutId) { - log.warn('query returned after timeout: ' + cql); + self.emit('log', 'warn', 'query returned after timeout: ' + cql); return; } else { clearTimeout(timeoutId); @@ -375,8 +375,12 @@ end = new Date().getTime(); diff = (end - start); if (self.connectionInfo.log_time) { - logTiming.trace('CQL QUERY TIMING', {'query': query, 'parameterized_query': cqlString, 'args': args, - 'time': diff}); + self.emit('log', 'timing', { + 'query': query, + 'parameterized_query': cqlString, + 'args': args, + 'time': diff + }); } if (err) { @@ -494,11 +498,9 @@ if (!hostSpec) { continue; } var host = hostSpec.split(':'); if (host.length > 2) { - log.warn('malformed host entry "' + hostSpec + '" (skipping)'); - continue; - } - log.debug("adding " + hostSpec + " to working node list"); - this.connections.push(new ConnectionInPool({ + throw new Error('malformed host entry "' + hostSpec + '" (skipping)'); + } + var connection = new ConnectionInPool({ host: host[0], port: (isNaN(host[1])) ? 9160 : host[1], keyspace: config.keyspace, @@ -507,9 +509,16 @@ use_bigints: self.use_bigints, timeout: self.timeout, log_time: self.log_time - })); - } + }); + connection.on('log', function(level, message) { + self.emit('log', level, message); + }); + this.connections.push(connection); + } + + EventEmitter.call(this); }; +util.inherits(PooledConnection, EventEmitter); /** * increment the current node pointer, skipping over any bad nodes. has a side-effect of resetting @@ -572,7 +581,7 @@ if (recoverableError) { con.unhealthyAt = new Date().getTime(); con.taken = false; - log.warn('setting unhealthy from execute ' + con.connectionInfo.host + ':' + con.connectionInfo.port); + self.emit('log', 'warn', 'setting unhealthy from execute ' + con.connectionInfo.host + ':' + con.connectionInfo.port); // try again. self.execute(query, args, callback); } @@ -584,7 +593,7 @@ // individual connection has failed. con.unhealthyAt = new Date().getTime(); con.taken = false; - log.warn('setting unhealthy from catch outside execute ' + con.connectionInfo.host + ':' + con.connectionInfo.port); + self.emit('log', 'warn', 'setting unhealthy from catch outside execute ' + con.connectionInfo.host + ':' + con.connectionInfo.port); // try again. self.execute(query, args, callback); } ======================================= --- /lib/system.js Sat Jan 21 15:42:46 2012 +++ /lib/system.js Thu Jan 26 14:40:08 2012 @@ -15,7 +15,6 @@ * */ -var log = require('logmagic').local('node-cassandra-client.system'); var util = require('util'); var EventEmitter = require('events').EventEmitter; @@ -58,7 +57,10 @@ })(parts[0], parts[1], i); } this.length = i; + + EventEmitter.call(this); }; +util.inherits(Pool, EventEmitter); // makes the thrift connection+client. Pool.prototype._make_client = function(addr, port, i, callback) { @@ -72,12 +74,12 @@ var con = thrift.createConnection(addr, port); var self = this; con.on('error', function(err) { - log.error(err); + self.emit('log', 'error', err); self.connections[i] = null; self.connecting[i] = false; }); var client = thrift.createClient(Cassandra, con); - log.info('connected to ' + addr + ':' + port + '@' + i); + self.emit('log', 'info', 'connected to ' + addr + ':' + port + '@' + i); self.connections[i] = new ThriftConnection(con, client); if (callback) { callback(this.connections[i]); ======================================= --- /package.json Mon Jan 23 11:23:18 2012 +++ /package.json Thu Jan 26 14:40:08 2012 @@ -28,7 +28,6 @@ "dependencies": { "async": ">= 0.1.12", "thrift": ">= 0.6.0-1", - "logmagic": ">= 0.1.1", "whiskey": ">= 0.6.1", "node-uuid": ">= 1.3.3" }, ======================================= --- /test/test_driver.js Mon Jan 16 08:31:48 2012 +++ /test/test_driver.js Thu Jan 26 14:40:08 2012 @@ -21,7 +21,6 @@ var EventEmitter = require('events').EventEmitter; var http = require('http'); -var logmagic = require('logmagic'); var async = require('async'); var BigInteger = require('../lib/bigint').BigInteger; @@ -86,6 +85,12 @@ callback(null, con); }); var con = new Connection(connOptions); + con.on('log', function(level, message) { + if (['cql'].indexOf(level) !== -1) { + return; + } + console.log('log event: %s -- %j', level, message); + }); con.connect(function(err) { if (err) { callback(err, null); @@ -942,16 +947,16 @@ var logObjsCql = []; var logObjsTime = []; - logmagic.registerSink('cql_sink', function(module, level, message, obj) { - logObjsCql.push(arguments); - }); - - logmagic.registerSink('timing_sink', function(module, level, message, obj) { - logObjsTime.push(arguments); - }); - - logmagic.route('node-cassandra-client.driver.cql', logmagic.TRACE1, 'cql_sink'); - logmagic.route('node-cassandra-client.driver.timing', logmagic.TRACE1, 'timing_sink'); + var appendLog = function(level, message) { + if (level === 'cql') { + logObjsCql.push(message); + } + if (level === 'timing') { + logObjsTime.push(message); + } + }; + conn1.on('log', appendLog); + conn2.on('log', appendLog); conn1.execute('UPDATE CfUgly SET A=1 WHERE KEY=1', [], function(err) { var logObj; @@ -962,10 +967,10 @@ assert.equal(logObjsTime.length, 0); logObj = logObjsCql[0]; - assert.ok(logObj[3].hasOwnProperty('query')); - assert.ok(logObj[3].hasOwnProperty('parameterized_query')); - assert.ok(logObj[3].hasOwnProperty('args')); - assert.ok(!logObj[3].hasOwnProperty('time')); + assert.ok(logObj.hasOwnProperty('query')); + assert.ok(logObj.hasOwnProperty('parameterized_query')); + assert.ok(logObj.hasOwnProperty('args')); + assert.ok(!logObj.hasOwnProperty('time')); conn2.execute('SELECT A FROM CfUgly WHERE KEY=1', [], function(err, rows) { var logObj; @@ -977,14 +982,12 @@ assert.equal(logObjsTime.length, 1); logObj = logObjsTime[0]; - assert.ok(logObj[3].hasOwnProperty('query')); - assert.ok(logObj[3].hasOwnProperty('parameterized_query')); - assert.ok(logObj[3].hasOwnProperty('args')); - assert.ok(logObj[3].hasOwnProperty('time')); - - conn1.shutdown(); - conn2.shutdown(); - test.finish(); + assert.ok(logObj.hasOwnProperty('query')); + assert.ok(logObj.hasOwnProperty('parameterized_query')); + assert.ok(logObj.hasOwnProperty('args')); + assert.ok(logObj.hasOwnProperty('time')); + + conn1.shutdown(conn2.shutdown(test.finish)); }); }); }; ============================================================================== Revision: 764dd54a7bc3 Author: Gary Dusbabek Date: Mon Jan 30 10:26:55 2012 Log: Merge commit '9888be187a23a2a2b5ca8a01e7710b7e48f9f00c' into 16/remove_logmagic http://code.google.com/a/apache-extras.org/p/cassandra-node/source/detail?r=764dd54a7bc3 Modified: /lib/driver.js /test/test_driver.js ======================================= --- /lib/driver.js Mon Jan 30 10:16:45 2012 +++ /lib/driver.js Mon Jan 30 10:26:55 2012 @@ -17,10 +17,6 @@ /** node.js driver for Cassandra-CQL. */ -var log = require('logmagic').local('node-cassandra-client.driver'); -var logCql = require('logmagic').local('node-cassandra-client.driver.cql'); -var logTiming = require('logmagic').local('node-cassandra-client.driver.timing'); - var util = require('util'); var constants = require('constants'); var EventEmitter = require('events').EventEmitter; @@ -189,12 +185,14 @@ */ var Connection = module.exports.Connection = function(options) { options = options || {}; - log.info('connecting ' + options.host + ':' + options.port); this.validators = {}; this.client = null; this.connectionInfo = options; this.timeout = options.timeout || DEFAULT_CONNECTION_TIMEOUT; + + EventEmitter.call(this); }; +util.inherits(Connection, EventEmitter); /** @@ -205,6 +203,8 @@ var self = this, timeoutId; + self.emit('log', 'info', 'connecting ' + self.connectionInfo.host + ':' + self.connectionInfo.port); + // build connection here, so that timeouts on bad hosts happen now and not in the constructor. this.con = thrift.createConnection(self.connectionInfo.host, self.connectionInfo.port); this.con.on('error', function(err) { @@ -215,7 +215,7 @@ this.con.on('close', function() { clearTimeout(timeoutId); - log.info(self.connectionInfo.host + ':' + self.connectionInfo.port + ' is closed'); + self.emit('log', 'info', self.connectionInfo.host + ':' + self.connectionInfo.port + ' is closed'); }); this.con.on('connect', function() { @@ -359,7 +359,7 @@ start, end, diff; start = new Date().getTime(); - logCql.trace('CQL QUERY', {'query': query, 'parameterized_query': cqlString, 'args': args}); + self.emit('log', 'cql', {'query': query, 'parameterized_query': cqlString, 'args': args}); // if a connection dies at the right place, execute_cql_query never returns. make sure the callback gets called. var timeoutId = setTimeout(function() { @@ -368,7 +368,7 @@ }, this.timeout); // todo: should we disambiguate connection timeout vs query timeout? self.client.execute_cql_query(cql, ttypes.Compression.NONE, function(err, res) { if (!timeoutId) { - log.warn('query returned after timeout: ' + cql); + self.emit('log', 'warn', 'query returned after timeout: ' + cql); return; } else { clearTimeout(timeoutId); @@ -377,8 +377,12 @@ end = new Date().getTime(); diff = (end - start); if (self.connectionInfo.log_time) { - logTiming.trace('CQL QUERY TIMING', {'query': query, 'parameterized_query': cqlString, 'args': args, - 'time': diff}); + self.emit('log', 'timing', { + 'query': query, + 'parameterized_query': cqlString, + 'args': args, + 'time': diff + }); } if (err) { @@ -496,11 +500,9 @@ if (!hostSpec) { continue; } var host = hostSpec.split(':'); if (host.length > 2) { - log.warn('malformed host entry "' + hostSpec + '" (skipping)'); - continue; - } - log.debug("adding " + hostSpec + " to working node list"); - this.connections.push(new ConnectionInPool({ + throw new Error('malformed host entry "' + hostSpec + '" (skipping)'); + } + var connection = new ConnectionInPool({ host: host[0], port: (isNaN(host[1])) ? 9160 : host[1], keyspace: config.keyspace, @@ -509,9 +511,16 @@ use_bigints: self.use_bigints, timeout: self.timeout, log_time: self.log_time - })); - } + }); + connection.on('log', function(level, message) { + self.emit('log', level, message); + }); + this.connections.push(connection); + } + + EventEmitter.call(this); }; +util.inherits(PooledConnection, EventEmitter); /** * increment the current node pointer, skipping over any bad nodes. has a side-effect of resetting @@ -574,7 +583,7 @@ if (recoverableError) { con.unhealthyAt = new Date().getTime(); con.taken = false; - log.warn('setting unhealthy from execute ' + con.connectionInfo.host + ':' + con.connectionInfo.port); + self.emit('log', 'warn', 'setting unhealthy from execute ' + con.connectionInfo.host + ':' + con.connectionInfo.port); // try again. self.execute(query, args, callback); } @@ -586,7 +595,7 @@ // individual connection has failed. con.unhealthyAt = new Date().getTime(); con.taken = false; - log.warn('setting unhealthy from catch outside execute ' + con.connectionInfo.host + ':' + con.connectionInfo.port); + self.emit('log', 'warn', 'setting unhealthy from catch outside execute ' + con.connectionInfo.host + ':' + con.connectionInfo.port); // try again. self.execute(query, args, callback); } ======================================= --- /test/test_driver.js Mon Jan 30 10:16:45 2012 +++ /test/test_driver.js Mon Jan 30 10:26:55 2012 @@ -21,7 +21,6 @@ var EventEmitter = require('events').EventEmitter; var http = require('http'); -var logmagic = require('logmagic'); var async = require('async'); var BigInteger = require('../lib/bigint').BigInteger; @@ -86,6 +85,12 @@ callback(null, con); }); var con = new Connection(connOptions); + con.on('log', function(level, message) { + if (['cql'].indexOf(level) !== -1) { + return; + } + console.log('log event: %s -- %j', level, message); + }); con.connect(function(err) { if (err) { callback(err, null); @@ -941,16 +946,16 @@ var logObjsCql = []; var logObjsTime = []; - logmagic.registerSink('cql_sink', function(module, level, message, obj) { - logObjsCql.push(arguments); - }); - - logmagic.registerSink('timing_sink', function(module, level, message, obj) { - logObjsTime.push(arguments); - }); - - logmagic.route('node-cassandra-client.driver.cql', logmagic.TRACE1, 'cql_sink'); - logmagic.route('node-cassandra-client.driver.timing', logmagic.TRACE1, 'timing_sink'); + var appendLog = function(level, message) { + if (level === 'cql') { + logObjsCql.push(message); + } + if (level === 'timing') { + logObjsTime.push(message); + } + }; + conn1.on('log', appendLog); + conn2.on('log', appendLog); conn1.execute('UPDATE CfUgly SET A=1 WHERE KEY=1', [], function(err) { var logObj; @@ -961,10 +966,10 @@ assert.equal(logObjsTime.length, 0); logObj = logObjsCql[0]; - assert.ok(logObj[3].hasOwnProperty('query')); - assert.ok(logObj[3].hasOwnProperty('parameterized_query')); - assert.ok(logObj[3].hasOwnProperty('args')); - assert.ok(!logObj[3].hasOwnProperty('time')); + assert.ok(logObj.hasOwnProperty('query')); + assert.ok(logObj.hasOwnProperty('parameterized_query')); + assert.ok(logObj.hasOwnProperty('args')); + assert.ok(!logObj.hasOwnProperty('time')); conn2.execute('SELECT A FROM CfUgly WHERE KEY=1', [], function(err, rows) { var logObj; @@ -976,14 +981,12 @@ assert.equal(logObjsTime.length, 1); logObj = logObjsTime[0]; - assert.ok(logObj[3].hasOwnProperty('query')); - assert.ok(logObj[3].hasOwnProperty('parameterized_query')); - assert.ok(logObj[3].hasOwnProperty('args')); - assert.ok(logObj[3].hasOwnProperty('time')); - - conn1.shutdown(); - conn2.shutdown(); - test.finish(); + assert.ok(logObj.hasOwnProperty('query')); + assert.ok(logObj.hasOwnProperty('parameterized_query')); + assert.ok(logObj.hasOwnProperty('args')); + assert.ok(logObj.hasOwnProperty('time')); + + conn1.shutdown(conn2.shutdown(test.finish)); }); }); };