Name: js-handler/node_modules/restify/node_modules/bunyan/test/cli.test.js 
1:
/*
2:
 * Copyright (c) 2012 Trent Mick. All rights reserved.
3:
 *
4:
 * Test the `bunyan` CLI.
5:
 */
6:
 
7:
var path = require('path');
8:
var exec = require('child_process').exec;
9:
var _ = require('util').format;
10:
var debug = console.warn;
11:
 
12:
// node-tap API
13:
if (require.cache[__dirname + '/tap4nodeunit.js'])
14:
        delete require.cache[__dirname + '/tap4nodeunit.js'];
15:
var tap4nodeunit = require('./tap4nodeunit.js');
16:
var after = tap4nodeunit.after;
17:
var before = tap4nodeunit.before;
18:
var test = tap4nodeunit.test;
19:
 
20:
 
21:
 
22:
var BUNYAN = path.resolve(__dirname, '../bin/bunyan');
23:
 
24:
//child = exec('cat *.js bad_file | wc -l',
25:
//  function (error, stdout, stderr) {
26:
//    console.log('stdout: ' + stdout);
27:
//    console.log('stderr: ' + stderr);
28:
//    if (error !== null) {
29:
//      console.log('exec error: ' + error);
30:
//    }
31:
//});
32:
 
33:
test('--version', function (t) {
34:
    var version = require('../package.json').version;
35:
    exec(BUNYAN + ' --version', function (err, stdout, stderr) {
36:
        t.ifError(err)
37:
        t.equal(stdout, 'bunyan ' + version + '\n');
38:
        t.end();
39:
    });
40:
});
41:
 
42:
test('--help', function (t) {
43:
    exec(BUNYAN + ' --help', function (err, stdout, stderr) {
44:
        t.ifError(err)
45:
        t.ok(stdout.indexOf('General options:') !== -1);
46:
        t.end();
47:
    });
48:
});
49:
 
50:
test('-h', function (t) {
51:
    exec(BUNYAN + ' -h', function (err, stdout, stderr) {
52:
        t.ifError(err)
53:
        t.ok(stdout.indexOf('General options:') !== -1);
54:
        t.end();
55:
    });
56:
});
57:
 
58:
test('--bogus', function (t) {
59:
    exec(BUNYAN + ' --bogus', function (err, stdout, stderr) {
60:
        t.ok(err, 'should error out')
61:
        t.equal(err.code, 1, '... with exit code 1')
62:
        t.end();
63:
    });
64:
});
65:
 
66:
test('simple.log', function (t) {
67:
    exec(_('%s %s/corpus/simple.log', BUNYAN, __dirname),
68:
             function (err, stdout, stderr) {
69:
        t.ifError(err)
70:
        t.equal(stdout,
71:
            '[2012-02-08T22:56:52.856Z]  INFO: myservice/123 on example.com: '
72:
            + 'My message\n');
73:
        t.end();
74:
    });
75:
});
76:
test('cat simple.log', function (t) {
77:
    exec(_('cat %s/corpus/simple.log | %s', __dirname, BUNYAN),
78:
        function (err, stdout, stderr) {
79:
            t.ifError(err)
80:
            t.equal(stdout,
81:
                /* JSSTYLED */
82:
                '[2012-02-08T22:56:52.856Z]  INFO: myservice/123 on example.com: My message\n');
83:
            t.end();
84:
        }
85:
    );
86:
});
87:
test('simple.log with color', function (t) {
88:
    exec(_('%s --color %s/corpus/simple.log', BUNYAN, __dirname),
89:
        function (err, stdout, stderr) {
90:
        t.ifError(err)
91:
        t.equal(stdout,
92:
            /* JSSTYLED */
93:
            '[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: myservice/123 on example.com: \u001b[36mMy message\u001b[39m\n\u001b[0m');
94:
        t.end();
95:
    });
96:
});
97:
 
98:
test('extrafield.log', function (t) {
99:
    exec(_('%s %s/corpus/extrafield.log', BUNYAN, __dirname),
100:
             function (err, stdout, stderr) {
101:
        t.ifError(err)
102:
        t.equal(stdout,
103:
            '[2012-02-08T22:56:52.856Z]  INFO: myservice/123 on example.com: '
104:
            + 'My message (extra=field)\n');
105:
        t.end();
106:
    });
107:
});
108:
test('extrafield.log with color', function (t) {
109:
    exec(_('%s --color %s/corpus/extrafield.log', BUNYAN, __dirname),
110:
             function (err, stdout, stderr) {
111:
        t.ifError(err)
112:
        t.equal(stdout,
113:
            '[2012-02-08T22:56:52.856Z] \u001b[36m INFO\u001b[39m: '
114:
            + 'myservice/123 '
115:
            + 'on example.com: \u001b[36mMy message\u001b[39m'
116:
            + '\u001b[90m (extra=field)\u001b[39m\n\u001b[0m');
117:
        t.end();
118:
    });
119:
});
120:
 
121:
test('bogus.log', function (t) {
122:
    exec(_('%s %s/corpus/bogus.log', BUNYAN, __dirname),
123:
             function (err, stdout, stderr) {
124:
        t.ifError(err)
125:
        t.equal(stdout, 'not a JSON line\n{"hi": "there"}\n');
126:
        t.end();
127:
    });
128:
});
129:
 
130:
test('bogus.log -j', function (t) {
131:
    exec(_('%s -j %s/corpus/bogus.log', BUNYAN, __dirname),
132:
             function (err, stdout, stderr) {
133:
        t.ifError(err)
134:
        t.equal(stdout, 'not a JSON line\n{"hi": "there"}\n');
135:
        t.end();
136:
    });
137:
});
138:
 
139:
test('all.log', function (t) {
140:
    exec(_('%s %s/corpus/all.log', BUNYAN, __dirname),
141:
             function (err, stdout, stderr) {
142:
        // Just make sure don't blow up on this.
143:
        t.ifError(err)
144:
        t.end();
145:
    });
146:
});
147:
 
148:
test('simple.log doesnotexist1.log doesnotexist2.log', function (t) {
149:
    exec(_('%s %s/corpus/simple.log doesnotexist1.log doesnotexist2.log',
150:
                 BUNYAN, __dirname),
151:
        function (err, stdout, stderr) {
152:
            t.ok(err)
153:
            t.equal(err.code, 2)
154:
            t.equal(stdout,
155:
                /* JSSTYLED */
156:
                '[2012-02-08T22:56:52.856Z]  INFO: myservice/123 on example.com: My message\n');
157:
            // Note: node v0.6.10:
158:
            //   ENOENT, no such file or directory 'asdf.log'
159:
            // but node v0.6.14:
160:
            //   ENOENT, open 'asdf.log'
161:
            // Somewhat annoying change.
162:
            t.equal(stderr,
163:
                'bunyan: ENOENT, open \'doesnotexist1.log\'\nbunyan: ENOENT, '
164:
                + 'open \'doesnotexist2.log\'\n');
165:
            t.end();
166:
        }
167:
    );
168:
});
169:
 
170:
test('multiple logs', function (t) {
171:
    var cmd = _('%s %s/corpus/log1.log %s/corpus/log2.log',
172:
        BUNYAN, __dirname, __dirname);
173:
    exec(cmd, function (err, stdout, stderr) {
174:
        t.ifError(err);
175:
        t.equal(stdout, [
176:
            /* BEGIN JSSTYLED */
177:
            '[2012-05-08T16:57:55.586Z]  INFO: agent1/73267 on headnode: message\n',
178:
            '[2012-05-08T16:58:55.586Z]  INFO: agent2/73267 on headnode: message\n',
179:
            '[2012-05-08T17:01:49.339Z]  INFO: agent2/73267 on headnode: message\n',
180:
            '[2012-05-08T17:02:47.404Z]  INFO: agent2/73267 on headnode: message\n',
181:
            '[2012-05-08T17:02:49.339Z]  INFO: agent1/73267 on headnode: message\n',
182:
            '[2012-05-08T17:02:49.404Z]  INFO: agent1/73267 on headnode: message\n',
183:
            '[2012-05-08T17:02:49.404Z]  INFO: agent1/73267 on headnode: message\n',
184:
            '[2012-05-08T17:02:57.404Z]  INFO: agent2/73267 on headnode: message\n',
185:
            '[2012-05-08T17:08:01.105Z]  INFO: agent2/76156 on headnode: message\n',
186:
            /* END JSSTYLED */
187:
        ].join(''));
188:
        t.end();
189:
    });
190:
});
191:
 
192:
test('multiple logs, bunyan format', function (t) {
193:
    var cmd = _('%s -o bunyan %s/corpus/log1.log %s/corpus/log2.log',
194:
        BUNYAN, __dirname, __dirname);
195:
    exec(cmd, function (err, stdout, stderr) {
196:
        t.ifError(err);
197:
        t.equal(stdout, [
198:
            /* BEGIN JSSTYLED */
199:
            '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T16:57:55.586Z","v":0}',
200:
            '{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T16:58:55.586Z","v":0}',
201:
            '{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:01:49.339Z","v":0}',
202:
            '{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:47.404Z","v":0}',
203:
            '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:49.339Z","v":0}',
204:
            '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:49.404Z","v":0}',
205:
            '{"name":"agent1","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:49.404Z","v":0}',
206:
            '{"name":"agent2","pid":73267,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:02:57.404Z","v":0}',
207:
            '{"name":"agent2","pid":76156,"hostname":"headnode","level":30,"msg":"message","time":"2012-05-08T17:08:01.105Z","v":0}',
208:
            ''
209:
            /* END JSSTYLED */
210:
        ].join('\n'));
211:
        t.end();
212:
    });
213:
});
214:
 
215:
test('log1.log.gz', function (t) {
216:
    exec(_('%s %s/corpus/log1.log.gz', BUNYAN, __dirname),
217:
             function (err, stdout, stderr) {
218:
        t.ifError(err);
219:
        t.equal(stdout, [
220:
            /* BEGIN JSSTYLED */
221:
            '[2012-05-08T16:57:55.586Z]  INFO: agent1/73267 on headnode: message\n',
222:
            '[2012-05-08T17:02:49.339Z]  INFO: agent1/73267 on headnode: message\n',
223:
            '[2012-05-08T17:02:49.404Z]  INFO: agent1/73267 on headnode: message\n',
224:
            '[2012-05-08T17:02:49.404Z]  INFO: agent1/73267 on headnode: message\n',
225:
            /* END JSSTYLED */
226:
        ].join(''));
227:
        t.end();
228:
    });
229:
});
230:
 
231:
test('mixed text and gzip logs', function (t) {
232:
    var cmd = _('%s %s/corpus/log1.log.gz %s/corpus/log2.log',
233:
        BUNYAN, __dirname, __dirname);
234:
    exec(cmd, function (err, stdout, stderr) {
235:
        t.ifError(err);
236:
        t.equal(stdout, [
237:
            /* BEGIN JSSTYLED */
238:
            '[2012-05-08T16:57:55.586Z]  INFO: agent1/73267 on headnode: message\n',
239:
            '[2012-05-08T16:58:55.586Z]  INFO: agent2/73267 on headnode: message\n',
240:
            '[2012-05-08T17:01:49.339Z]  INFO: agent2/73267 on headnode: message\n',
241:
            '[2012-05-08T17:02:47.404Z]  INFO: agent2/73267 on headnode: message\n',
242:
            '[2012-05-08T17:02:49.339Z]  INFO: agent1/73267 on headnode: message\n',
243:
            '[2012-05-08T17:02:49.404Z]  INFO: agent1/73267 on headnode: message\n',
244:
            '[2012-05-08T17:02:49.404Z]  INFO: agent1/73267 on headnode: message\n',
245:
            '[2012-05-08T17:02:57.404Z]  INFO: agent2/73267 on headnode: message\n',
246:
            '[2012-05-08T17:08:01.105Z]  INFO: agent2/76156 on headnode: message\n',
247:
            /* END JSSTYLED */
248:
        ].join(''));
249:
        t.end();
250:
    });
251:
});
252:
 
253:
test('--level 40', function (t) {
254:
    expect = [
255:
        /* BEGIN JSSTYLED */
256:
        '# levels\n',
257:
        '[2012-02-08T22:56:53.856Z]  WARN: myservice/123 on example.com: My message\n',
258:
        '[2012-02-08T22:56:54.856Z] ERROR: myservice/123 on example.com: My message\n',
259:
        '[2012-02-08T22:56:55.856Z] LVL55: myservice/123 on example.com: My message\n',
260:
        '[2012-02-08T22:56:56.856Z] FATAL: myservice/123 on example.com: My message\n',
261:
        '\n',
262:
        '# extra fields\n',
263:
        '\n',
264:
        '# bogus\n',
265:
        'not a JSON line\n',
266:
        '{"hi": "there"}\n'
267:
        /* END JSSTYLED */
268:
    ].join('');
269:
    exec(_('%s -l 40 %s/corpus/all.log', BUNYAN, __dirname),
270:
             function (err, stdout, stderr) {
271:
        t.ifError(err);
272:
        t.equal(stdout, expect);
273:
        exec(_('%s --level 40 %s/corpus/all.log', BUNYAN, __dirname),
274:
                 function (err, stdout, stderr) {
275:
            t.ifError(err);
276:
            t.equal(stdout, expect);
277:
            t.end();
278:
        });
279:
    });
280:
});
281:
 
282:
test('--condition "level === 10 && pid === 123"', function (t) {
283:
    var expect = [
284:
        '# levels\n',
285:
        /* JSSTYLED */
286:
        '[2012-02-08T22:56:50.856Z] TRACE: myservice/123 on example.com: My message\n',
287:
        '\n',
288:
        '# extra fields\n',
289:
        '\n',
290:
        '# bogus\n',
291:
        'not a JSON line\n',
292:
        '{"hi": "there"}\n'
293:
    ].join('');
294:
    var cmd = _('%s -c "level === 10 && pid === 123" %s/corpus/all.log',
295:
        BUNYAN, __dirname);
296:
    exec(cmd, function (err, stdout, stderr) {
297:
        t.ifError(err);
298:
        t.equal(stdout, expect);
299:
        var cmd = _(
300:
            '%s --condition "level === 10 && pid === 123" %s/corpus/all.log',
301:
            BUNYAN, __dirname);
302:
        exec(cmd, function (err, stdout, stderr) {
303:
            t.ifError(err);
304:
            t.equal(stdout, expect);
305:
            t.end();
306:
        });
307:
    });
308:
});
309:
 
310:
// multiple
311:
// not sure if this is a bug or a feature.  let's call it a feature!
312:
test('multiple --conditions', function (t) {
313:
    var expect = [
314:
        '# levels\n',
315:
        /* JSSTYLED */
316:
        '[2012-02-08T22:56:53.856Z]  WARN: myservice/1 on example.com: My message\n',
317:
        '\n',
318:
        '# extra fields\n',
319:
        '\n',
320:
        '# bogus\n',
321:
        'not a JSON line\n',
322:
        '{"hi": "there"}\n'
323:
    ].join('');
324:
    exec(_('%s %s/corpus/all.log ' +
325:
                 '-c "if (level === 40) pid = 1; true" ' +
326:
                 '-c "pid === 1"', BUNYAN, __dirname),
327:
             function (err, stdout, stderr) {
328:
        t.ifError(err);
329:
        t.equal(stdout, expect);
330:
        t.end();
331:
    });
332:
});
333:
 
334:
// https://github.com/trentm/node-bunyan/issues/30
335:
//
336:
// One of the records in corpus/withreq.log has a 'req'
337:
// field with no 'headers'. Ditto for the 'res' field.
338:
test('robust req handling', function (t) {
339:
    var expect = [
340:
        /* BEGIN JSSTYLED */
341:
        '[2012-08-08T10:25:47.636Z] DEBUG: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: headAgentProbes respond (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, route=HeadAgentProbes, contentMD5=11FxOYiYfpMxmANj4kGJzg==)',
342:
        '[2012-08-08T10:25:47.637Z]  INFO: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: HeadAgentProbes handled: 200 (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, audit=true, remoteAddress=10.2.207.2, remotePort=50394, latency=3, secure=false, _audit=true, req.version=*)',
343:
        '    HEAD /agentprobes?agent=ccf92af9-0b24-46b6-ab60-65095fdd3037 HTTP/1.1',
344:
        '    accept: application/json',
345:
        '    content-type: application/json',
346:
        '    host: 10.2.207.16',
347:
        '    connection: keep-alive',
348:
        '    --',
349:
        '    HTTP/1.1 200 OK',
350:
        '    content-md5: 11FxOYiYfpMxmANj4kGJzg==',
351:
        '    access-control-allow-origin: *',
352:
        '    access-control-allow-headers: Accept, Accept-Version, Content-Length, Content-MD5, Content-Type, Date, X-Api-Version',
353:
        '    access-control-allow-methods: HEAD',
354:
        '    access-control-expose-headers: X-Api-Version, X-Request-Id, X-Response-Time',
355:
        '    connection: Keep-Alive',
356:
        '    date: Wed, 08 Aug 2012 10:25:47 GMT',
357:
        '    server: Amon Master/1.0.0',
358:
        '    x-request-id: cce79d15-ffc2-487c-a4e4-e940bdaac31e',
359:
        '    x-response-time: 3',
360:
        '    --',
361:
        '    route: {',
362:
        '      "name": "HeadAgentProbes",',
363:
        '      "version": false',
364:
        '    }',
365:
        '[2012-08-08T10:25:47.637Z]  INFO: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: HeadAgentProbes handled: 200 (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, audit=true, remoteAddress=10.2.207.2, remotePort=50394, latency=3, secure=false, _audit=true, req.version=*)',
366:
        '    HEAD /agentprobes?agent=ccf92af9-0b24-46b6-ab60-65095fdd3037 HTTP/1.1',
367:
        '    --',
368:
        '    route: {',
369:
        '      "name": "HeadAgentProbes",',
370:
        '      "version": false',
371:
        '    }'
372:
        /* END JSSTYLED */
373:
    ].join('\n') + '\n';
374:
    exec(_('%s %s/corpus/withreq.log', BUNYAN, __dirname),
375:
             function (err, stdout, stderr) {
376:
        t.ifError(err);
377:
        t.equal(stdout, expect);
378:
        t.end();
379:
    });
380:
});