paymentsservice: structure logs (open-telemetry#520)

Use Pino's [mergingObject](https://github.com/pinojs/pino/blob/master/docs/api.md#mergingobject-object) parameter to add context as JSON
rather than in the message parameter, which is now more generic (like an event name).

Also factor out logger so it is instantiated once for the whole service and upgrade pino.

Also remove unneeded comments.

Signed-off-by: Naseem Ullah <[email protected]>

Signed-off-by: Naseem Ullah <[email protected]>
Co-authored-by: Austin Parker <[email protected]>
Co-authored-by: Carter Socha <[email protected]>

Author: 3 people

src/paymentservice/charge.js

@@ -12,25 +12,20 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
-// Npm
 const {context, propagation, trace} = require('@opentelemetry/api');
 const cardValidator = require('simple-card-validator');
-const pino = require('pino');
 const { v4: uuidv4 } = require('uuid');
 
-// Setup
-const logger = pino();
+const logger = require('./logger');
 const tracer = trace.getTracer('paymentservice');
 
-// Functions
 module.exports.charge = request => {
   const span = tracer.startSpan('charge');
 
   const { creditCardNumber: number,
     creditCardExpirationYear: year,
     creditCardExpirationMonth: month
   } = request.creditCard;
-  const { units, nanos, currencyCode } = request.amount;
   const currentMonth = new Date().getMonth() + 1;
   const currentYear = new Date().getFullYear();
   const lastFourDigits = number.substr(-4);
@@ -51,7 +46,7 @@ module.exports.charge = request => {
   if (!['visa', 'mastercard'].includes(cardType)) {
     throw new Error(`Sorry, we cannot process ${cardType} credit cards. Only VISA or MasterCard is accepted.`);
   }
-  
+
   if ((currentYear * 12 + currentMonth) > (year * 12 + month)) {
     throw new Error(`The credit card (ending ${lastFourDigits}) expired on ${month}/${year}.`);
   }
@@ -66,7 +61,8 @@ module.exports.charge = request => {
 
   span.end();
 
-  logger.info(`Transaction ${transactionId}: ${cardType} ending ${lastFourDigits} | Amount: ${units}.${nanos} ${currencyCode}`);
+  const { units, nanos, currencyCode } = request.amount;
+  logger.info({transactionId, cardType, lastFourDigits, amount: { units, nanos, currencyCode }}, "Transaction complete.");
 
   return { transactionId }
 }

src/paymentservice/index.js

@@ -12,17 +12,14 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
-// Npm
 const grpc = require('@grpc/grpc-js')
 const protoLoader = require('@grpc/proto-loader')
 const health = require('grpc-js-health-check')
 const opentelemetry = require('@opentelemetry/api')
-const pino = require('pino')
 
-// Local
 const charge = require('./charge')
+const logger = require('./logger')
 
-// Functions
 function chargeServiceHandler(call, callback) {
   const span = opentelemetry.trace.getActiveSpan();
 
@@ -31,13 +28,13 @@ function chargeServiceHandler(call, callback) {
     span.setAttributes({
       'app.payment.amount': parseFloat(`${amount.units}.${amount.nanos}`)
     })
-    logger.info(`PaymentService#Charge invoked by: ${JSON.stringify(call.request)}`)
+    logger.info({ request: call.request }, "Charge request received.")
 
     const response = charge.charge(call.request)
     callback(null, response)
 
   } catch (err) {
-    logger.warn(err)
+    logger.warn({ err })
 
     span.recordException(err)
     span.setStatus({ code: opentelemetry.SpanStatusCode.ERROR })
@@ -46,14 +43,11 @@ function chargeServiceHandler(call, callback) {
   }
 }
 
-// Functions
 async function closeGracefully(signal) {
   server.forceShutdown()
   process.kill(process.pid, signal)
 }
 
-// Main
-const logger = pino()
 const hipsterShopPackage = grpc.loadPackageDefinition(protoLoader.loadSync('demo.proto'))
 const server = new grpc.Server()
 
@@ -65,12 +59,12 @@ server.addService(hipsterShopPackage.hipstershop.PaymentService.service, { charg
 
 server.bindAsync(`0.0.0.0:${process.env['PAYMENT_SERVICE_PORT']}`, grpc.ServerCredentials.createInsecure(), (err, port) => {
   if (err) {
-    return logger.error(err)
+    return logger.error({ err })
   }
 
   logger.info(`PaymentService gRPC server started on port ${port}`)
   server.start()
-  }
+}
 )
 
 process.once('SIGINT', closeGracefully)

src/paymentservice/logger.js

@@ -0,0 +1,3 @@
+const pino = require('pino');
+
+module.exports = pino();