index.test.js 18 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671
  1. 'use strict';
  2. const assume = require('assume');
  3. const { format } = require('logform');
  4. const Writable = require('readable-stream/writable');
  5. const TransportStream = require('../');
  6. const Parent = require('./fixtures/parent');
  7. const { testLevels, testOrder } = require('./fixtures');
  8. const {
  9. infosFor,
  10. logFor,
  11. levelAndMessage,
  12. toException,
  13. toWriteReq
  14. } = require('abstract-winston-transport/utils');
  15. const { LEVEL, MESSAGE } = require('triple-beam');
  16. /*
  17. * Returns the provided `info` object with the appropriate LEVEL,
  18. * and MESSAGE symbols defined.
  19. */
  20. function infoify(info) {
  21. info[LEVEL] = info.level;
  22. info[MESSAGE] = info.message;
  23. return info;
  24. };
  25. describe('TransportStream', () => {
  26. it('should have the appropriate methods defined', () => {
  27. const transport = new TransportStream();
  28. assume(transport).instanceof(Writable);
  29. assume(transport._write).is.a('function');
  30. // eslint-disable-next-line no-undefined
  31. assume(transport.log).equals(undefined);
  32. });
  33. it('should accept a custom log function invoked on _write', () => {
  34. const log = logFor(1);
  35. const transport = new TransportStream({ log });
  36. assume(transport.log).equals(log);
  37. });
  38. it('should invoke a custom log function on _write', done => {
  39. const info = {
  40. [LEVEL]: 'test',
  41. level: 'test',
  42. message: 'Testing ... 1 2 3.'
  43. };
  44. const transport = new TransportStream({
  45. log(actual) {
  46. assume(actual).equals(info);
  47. done();
  48. }
  49. });
  50. transport.write(info);
  51. });
  52. describe('_write(info, enc, callback)', () => {
  53. it('should log to any level when { level: undefined }', done => {
  54. const expected = testOrder.map(levelAndMessage);
  55. const transport = new TransportStream({
  56. log: logFor(testOrder.length, (err, infos) => {
  57. if (err) {
  58. return done(err);
  59. }
  60. assume(infos.length).equals(expected.length);
  61. assume(infos).deep.equals(expected);
  62. done();
  63. })
  64. });
  65. expected.forEach(transport.write.bind(transport));
  66. });
  67. it('should not log when no info object is provided', done => {
  68. const expected = testOrder.map(levelAndMessage).map((info, i) => {
  69. if (testOrder.length > (i + 1)) {
  70. info.private = true;
  71. }
  72. return info;
  73. });
  74. const transport = new TransportStream({
  75. format: format(info => {
  76. if (info.private) return false;
  77. return info;
  78. })(),
  79. log: logFor(1, (err, infos) => {
  80. if (err) {
  81. return done(err);
  82. }
  83. assume(infos.length).equals(1);
  84. assume(infos.pop()).deep.equals(expected.pop());
  85. done();
  86. })
  87. });
  88. expected.forEach(transport.write.bind(transport));
  89. });
  90. it('should only log messages BELOW the level priority', done => {
  91. const expected = testOrder.map(levelAndMessage);
  92. const transport = new TransportStream({
  93. level: 'info',
  94. log: logFor(5, (err, infos) => {
  95. if (err) {
  96. return done(err);
  97. }
  98. assume(infos.length).equals(5);
  99. assume(infos).deep.equals(expected.slice(0, 5));
  100. done();
  101. })
  102. });
  103. transport.levels = testLevels;
  104. expected.forEach(transport.write.bind(transport));
  105. });
  106. it('{ level } should be ignored when { handleExceptions: true }', () => {
  107. const expected = testOrder.map(levelAndMessage).map(info => {
  108. info.exception = true;
  109. return info;
  110. });
  111. const transport = new TransportStream({
  112. level: 'info',
  113. log: logFor(testOrder.length, (err, infos) => {
  114. // eslint-disable-next-line no-undefined
  115. assume(err).equals(undefined);
  116. assume(infos.length).equals(expected.length);
  117. assume(infos).deep.equals(expected);
  118. })
  119. });
  120. transport.levels = testLevels;
  121. expected.forEach(transport.write.bind(transport));
  122. });
  123. describe('when { exception: true } in info', () => {
  124. it('should not invoke log when { handleExceptions: false }', done => {
  125. const expected = [{
  126. exception: true,
  127. [LEVEL]: 'error',
  128. level: 'error',
  129. message: 'Test exception handling'
  130. }, {
  131. [LEVEL]: 'test',
  132. level: 'test',
  133. message: 'Testing ... 1 2 3.'
  134. }];
  135. const transport = new TransportStream({
  136. log(info) {
  137. // eslint-disable-next-line no-undefined
  138. assume(info.exception).equals(undefined);
  139. done();
  140. }
  141. });
  142. expected.forEach(transport.write.bind(transport));
  143. });
  144. it('should invoke log when { handleExceptions: true }', done => {
  145. const actual = [];
  146. const expected = [{
  147. exception: true, [LEVEL]: 'error',
  148. level: 'error',
  149. message: 'Test exception handling'
  150. }, {
  151. [LEVEL]: 'test',
  152. level: 'test',
  153. message: 'Testing ... 1 2 3.'
  154. }];
  155. const transport = new TransportStream({
  156. handleExceptions: true,
  157. log(info, next) {
  158. actual.push(info);
  159. if (actual.length === expected.length) {
  160. assume(actual).deep.equals(expected);
  161. return done();
  162. }
  163. next();
  164. }
  165. });
  166. expected.forEach(transport.write.bind(transport));
  167. });
  168. });
  169. });
  170. describe('_writev(chunks, callback)', () => {
  171. it('invokes .log() for each of the valid chunks when necessary in streams plumbing', done => {
  172. const expected = infosFor({
  173. count: 50,
  174. levels: testOrder
  175. });
  176. const transport = new TransportStream({
  177. log: logFor(50 * testOrder.length, (err, infos) => {
  178. if (err) {
  179. return done(err);
  180. }
  181. assume(infos.length).equals(expected.length);
  182. assume(infos).deep.equals(expected);
  183. done();
  184. })
  185. });
  186. //
  187. // Make the standard _write throw to ensure that _writev is called.
  188. //
  189. transport._write = () => {
  190. throw new Error('TransportStream.prototype._write should never be called.');
  191. };
  192. transport.cork();
  193. expected.forEach(transport.write.bind(transport));
  194. transport.uncork();
  195. });
  196. it('should not log when no info object is provided in streams plumbing', done => {
  197. const expected = testOrder.map(levelAndMessage).map((info, i) => {
  198. if (testOrder.length > (i + 1)) {
  199. info.private = true;
  200. }
  201. return info;
  202. });
  203. const transport = new TransportStream({
  204. format: format(info => {
  205. if (info.private) {
  206. return false;
  207. }
  208. return info;
  209. })(),
  210. log: logFor(1, (err, infos) => {
  211. if (err) {
  212. return done(err);
  213. }
  214. assume(infos.length).equals(1);
  215. assume(infos.pop()).deep.equals(expected.pop());
  216. done();
  217. })
  218. });
  219. //
  220. // Make the standard _write throw to ensure that _writev is called.
  221. //
  222. transport._write = () => {
  223. throw new Error('TransportStream.prototype._write should never be called.');
  224. };
  225. transport.cork();
  226. expected.forEach(transport.write.bind(transport));
  227. transport.uncork();
  228. });
  229. it('ensures a format is applied to each info when no .logv is defined', done => {
  230. const expected = infosFor({ count: 10, levels: testOrder });
  231. const transport = new TransportStream({
  232. format: format.json(),
  233. log: logFor(10 * testOrder.length, (err, infos) => {
  234. if (err) {
  235. return done(err);
  236. }
  237. assume(infos.length).equals(expected.length);
  238. infos.forEach((info, i) => {
  239. assume(info[MESSAGE]).equals(JSON.stringify(expected[i]));
  240. });
  241. done();
  242. })
  243. });
  244. //
  245. // Make the standard _write throw to ensure that _writev is called.
  246. //
  247. transport._write = () => {
  248. throw new Error('TransportStream.prototype._write should never be called.');
  249. };
  250. transport.cork();
  251. expected.forEach(transport.write.bind(transport));
  252. transport.uncork();
  253. });
  254. it('invokes .logv with all valid chunks when necessary in streams plumbing', done => {
  255. const expected = infosFor({
  256. count: 50,
  257. levels: testOrder
  258. });
  259. const transport = new TransportStream({
  260. level: 'info',
  261. log() {
  262. throw new Error('.log() should never be called');
  263. },
  264. logv(chunks, callback) {
  265. assume(chunks.length).equals(250);
  266. callback(); // eslint-disable-line callback-return
  267. done();
  268. }
  269. });
  270. //
  271. // Make the standard _write throw to ensure that _writev is called.
  272. //
  273. transport._write = () => {
  274. throw new Error('TransportStream.prototype._write should never be called.');
  275. };
  276. transport.cork();
  277. transport.levels = testLevels;
  278. expected.forEach(transport.write.bind(transport));
  279. transport.uncork();
  280. });
  281. });
  282. describe('parent (i.e. "logger") ["pipe", "unpipe"]', () => {
  283. it('should define { level, levels } on "pipe"', done => {
  284. const parent = new Parent({
  285. level: 'info',
  286. levels: testLevels
  287. });
  288. const transport = new TransportStream({
  289. log(info, next) {
  290. assume(info.level).equals('info');
  291. assume(info.message).equals('ok sure');
  292. next();
  293. done();
  294. }
  295. });
  296. parent.pipe(transport);
  297. setImmediate(() => {
  298. assume(transport.level).equals(undefined);
  299. assume(transport.levels).equals(testLevels);
  300. assume(transport.parent).equals(parent);
  301. assume(transport.parent.level).equals('info');
  302. transport.write(infoify({ level: 'parrot', message: 'never logged' }));
  303. transport.write(infoify({ level: 'info', message: 'ok sure' }));
  304. });
  305. });
  306. it('should not overwrite existing { level } on "pipe"', done => {
  307. const parent = new Parent({
  308. level: 'info',
  309. levels: testLevels
  310. });
  311. const transport = new TransportStream({
  312. level: 'error',
  313. log(info, next) {
  314. assume(info.level).equals('error');
  315. assume(info.message).equals('ok sure');
  316. next();
  317. done();
  318. }
  319. });
  320. parent.pipe(transport);
  321. setImmediate(() => {
  322. assume(transport.level).equals('error');
  323. assume(transport.levels).equals(testLevels);
  324. assume(transport.parent).equals(parent);
  325. transport.write(infoify({ level: 'info', message: 'never logged' }));
  326. transport.write(infoify({ level: 'error', message: 'ok sure' }));
  327. });
  328. });
  329. it('should respond to changes in parent logging level', done => {
  330. const parent = new Parent({
  331. level: 'error',
  332. levels: testLevels
  333. });
  334. const transport = new TransportStream({
  335. log(info, next) {
  336. assume(info.level).equals('parrot');
  337. assume(info.message).equals('eventually log this');
  338. next();
  339. done();
  340. }
  341. });
  342. parent.pipe(transport);
  343. setImmediate(() => {
  344. assume(transport.levels).equals(testLevels);
  345. assume(transport.parent).equals(parent);
  346. transport.write(infoify({ level: 'info', message: 'never logged' }));
  347. parent.level = 'parrot';
  348. transport.write(infoify({ level: 'parrot', message: 'eventually log this' }));
  349. });
  350. });
  351. it('should unset parent on "unpipe"', done => {
  352. const parent = new Parent({
  353. level: 'info',
  354. levels: testLevels
  355. });
  356. const transport = new TransportStream({
  357. level: 'error',
  358. log() {}
  359. });
  360. //
  361. // Trigger "pipe" first so that transport.parent is set.
  362. //
  363. parent.pipe(transport);
  364. setImmediate(() => {
  365. assume(transport.parent).equals(parent);
  366. //
  367. // Now verify that after "unpipe" it is set to 'null'.
  368. //
  369. parent.unpipe(transport);
  370. setImmediate(() => {
  371. assume(transport.parent).equals(null);
  372. done();
  373. });
  374. });
  375. });
  376. it('should invoke a close method on "unpipe"', done => {
  377. const parent = new Parent({
  378. level: 'info',
  379. levels: testLevels
  380. });
  381. const transport = new TransportStream({
  382. log() {}
  383. });
  384. //
  385. // Test will only successfully complete when `close`
  386. // is invoked
  387. //
  388. transport.close = () => {
  389. assume(transport.parent).equals(null);
  390. done();
  391. };
  392. //
  393. // Trigger "pipe" first so that transport.parent is set.
  394. //
  395. parent.pipe(transport);
  396. setImmediate(() => {
  397. assume(transport.parent).equals(parent);
  398. parent.unpipe(transport);
  399. });
  400. });
  401. });
  402. describe('_accept(info)', function () {
  403. it('should filter only log messages BELOW the level priority', () => {
  404. const expected = testOrder
  405. .map(levelAndMessage)
  406. .map(toWriteReq);
  407. const transport = new TransportStream({
  408. level: 'info'
  409. });
  410. transport.levels = testLevels;
  411. const filtered = expected.filter(transport._accept, transport)
  412. .map(write => write.chunk.level);
  413. assume(filtered).deep.equals([
  414. 'error',
  415. 'warn',
  416. 'dog',
  417. 'cat',
  418. 'info'
  419. ]);
  420. });
  421. it('should filter out { exception: true } when { handleExceptions: false }', () => {
  422. const expected = testOrder
  423. .map(toException)
  424. .map(toWriteReq);
  425. const transport = new TransportStream({
  426. handleExceptions: false,
  427. level: 'info'
  428. });
  429. transport.levels = testLevels;
  430. const filtered = expected.filter(transport._accept, transport)
  431. .map(info => info.level);
  432. assume(filtered).deep.equals([]);
  433. });
  434. it('should include ALL { exception: true } when { handleExceptions: true }', () => {
  435. const expected = testOrder
  436. .map(toException)
  437. .map(toWriteReq);
  438. const transport = new TransportStream({
  439. handleExceptions: true,
  440. level: 'info'
  441. });
  442. transport.levels = testLevels;
  443. const filtered = expected.filter(transport._accept, transport)
  444. .map(write => write.chunk.level);
  445. assume(filtered).deep.equals(testOrder);
  446. });
  447. });
  448. describe('{ format }', function () {
  449. it('logs the output of the provided format', done => {
  450. const expected = {
  451. [LEVEL]: 'info',
  452. level: 'info',
  453. message: 'there will be json'
  454. };
  455. const transport = new TransportStream({
  456. format: format.json(),
  457. log(info) {
  458. assume(info[MESSAGE]).equals(JSON.stringify(expected));
  459. done();
  460. }
  461. });
  462. transport.write(expected);
  463. });
  464. it('treats the original object immutable', done => {
  465. const expected = {
  466. [LEVEL]: 'info',
  467. level: 'info',
  468. message: 'there will be json'
  469. };
  470. const transport = new TransportStream({
  471. format: format.json(),
  472. log(info) {
  473. assume(info).not.equals(expected);
  474. done();
  475. }
  476. });
  477. transport.write(expected);
  478. });
  479. it('_write continues to write after a format throws', done => {
  480. const transport = new TransportStream({
  481. format: format.printf((info) => {
  482. // Set a trap.
  483. if (info.message === 'ENDOR') {
  484. throw new Error('ITS A TRAP!');
  485. }
  486. return info.message;
  487. }),
  488. log(info, callback) {
  489. callback();
  490. assume(info.level).equals('info');
  491. assume(info.message).equals('safe');
  492. done();
  493. }
  494. });
  495. try {
  496. transport.write({ level: 'info', message: 'ENDOR' });
  497. } catch (ex) {
  498. assume(ex.message).equals('ITS A TRAP!');
  499. }
  500. transport.write({ level: 'info', message: 'safe' });
  501. });
  502. it('_writev continues to write after a format throws', done => {
  503. const transport = new TransportStream({
  504. format: format.printf((info) => {
  505. // Set a trap.
  506. if (info.message === 'ENDOR') {
  507. throw new Error('ITS A TRAP!');
  508. }
  509. return info.message;
  510. }),
  511. log(info, callback) {
  512. assume(info.level).is.a('string');
  513. assume(info.message).is.a('string');
  514. callback();
  515. if (info.message === 'safe') {
  516. done();
  517. }
  518. }
  519. });
  520. const infos = infosFor({
  521. count: 10,
  522. levels: testOrder
  523. });
  524. try {
  525. transport.cork();
  526. infos.forEach(info => transport.write(info));
  527. transport.write({ level: 'info', message: 'ENDOR' });
  528. transport.uncork();
  529. } catch (ex) {
  530. assume(ex.message).equals('ITS A TRAP!');
  531. }
  532. transport.write({ level: 'info', message: 'safe' });
  533. });
  534. });
  535. describe('{ silent }', () => {
  536. const silentTransport = new TransportStream({
  537. silent: true,
  538. format: format.json(),
  539. log() {
  540. assume(false).true('.log() was called improperly');
  541. }
  542. });
  543. it('{ silent: true } ._write() never calls `.log`', done => {
  544. const expected = {
  545. [LEVEL]: 'info',
  546. level: 'info',
  547. message: 'there will be json'
  548. };
  549. silentTransport.write(expected);
  550. setImmediate(() => done());
  551. });
  552. it('{ silent: true } ._writev() never calls `.log`', done => {
  553. const expected = {
  554. [LEVEL]: 'info',
  555. level: 'info',
  556. message: 'there will be json'
  557. };
  558. silentTransport.cork();
  559. for (let i = 0; i < 15; i++) {
  560. silentTransport.write(expected);
  561. }
  562. silentTransport.uncork();
  563. setImmediate(() => done());
  564. });
  565. it('{ silent: true } ensures ._accept(write) always returns false', () => {
  566. const accepted = silentTransport._accept({ chunk: {} });
  567. assume(accepted).false();
  568. });
  569. });
  570. });