Merge pull request #824 from sasjs/startComputeJob-issue

feat(request-client): implemented verbose mode

src/SASjs.ts

@@ -854,6 +854,7 @@ export default class SASjs {
    * @param pollOptions - an object that represents poll interval(milliseconds) and maximum amount of attempts. Object example: { maxPollCount: 24 * 60 * 60, pollInterval: 1000 }. More information available at src/api/viya/pollJobState.ts.
    * @param printPid - a boolean that indicates whether the function should print (PID) of the started job.
    * @param variables - an object that represents macro variables.
+   * @param verboseMode - boolean to enable verbose mode (log every HTTP response).
    */
   public async startComputeJob(
     sasJob: string,
@@ -863,7 +864,8 @@ export default class SASjs {
     waitForResult?: boolean,
     pollOptions?: PollOptions,
     printPid = false,
-    variables?: MacroVar
+    variables?: MacroVar,
+    verboseMode?: boolean
   ) {
     config = {
       ...this.sasjsConfig,
@@ -877,6 +879,9 @@ export default class SASjs {
       )
     }
 
+    if (verboseMode) this.requestClient?.enableVerboseMode()
+    else this.requestClient?.disableVerboseMode()
+
     return this.sasViyaApiClient?.executeComputeJob(
       sasJob,
       config.contextName,

src/job-execution/FileUploader.ts

@@ -1,8 +1,7 @@
 import {
   getValidJson,
   parseSasViyaDebugResponse,
-  parseWeboutResponse,
-  SASJS_LOGS_SEPARATOR
+  parseWeboutResponse
 } from '../utils'
 import { UploadFile } from '../types/UploadFile'
 import {

src/request/RequestClient.ts

@@ -20,6 +20,7 @@ import {
   createAxiosInstance
 } from '../utils'
 import { InvalidSASjsCsrfError } from '../types/errors/InvalidSASjsCsrfError'
+import { inspect } from 'util'
 
 export interface HttpClient {
   get<T>(
@@ -59,6 +60,7 @@ export interface HttpClient {
 export class RequestClient implements HttpClient {
   private requests: SASjsRequest[] = []
   private requestsLimit: number = 10
+  private httpInterceptor?: number
 
   protected csrfToken: CsrfToken = { headerName: '', value: '' }
   protected fileUploadCsrfToken: CsrfToken | undefined
@@ -70,6 +72,7 @@ export class RequestClient implements HttpClient {
     requestsLimit?: number
   ) {
     this.createHttpClient(baseUrl, httpsAgentOptions)
+
     if (requestsLimit) this.requestsLimit = requestsLimit
   }
 
@@ -180,6 +183,7 @@ export class RequestClient implements HttpClient {
       responseType: contentType === 'text/plain' ? 'text' : 'json',
       withCredentials: true
     }
+
     if (contentType === 'text/plain') {
       requestConfig.transformResponse = undefined
     }
@@ -389,6 +393,105 @@ export class RequestClient implements HttpClient {
       })
   }
 
+  /**
+   * Adds colors to the string.
+   * @param str - string to be prettified.
+   * @returns - prettified string
+   */
+  private prettifyString = (str: any) => inspect(str, { colors: true })
+
+  /**
+   * Formats HTTP request/response body.
+   * @param body - HTTP request/response body.
+   * @returns - formatted string.
+   */
+  private parseInterceptedBody = (body: any) => {
+    if (!body) return ''
+
+    let parsedBody
+
+    // Tries to parse body into JSON object.
+    if (typeof body === 'string') {
+      try {
+        parsedBody = JSON.parse(body)
+      } catch (error) {
+        parsedBody = body
+      }
+    } else {
+      parsedBody = body
+    }
+
+    const bodyLines = this.prettifyString(parsedBody).split('\n')
+
+    // Leaves first 50 lines
+    if (bodyLines.length > 51) {
+      bodyLines.splice(50)
+      bodyLines.push('...')
+    }
+
+    return bodyLines.join('\n')
+  }
+
+  private defaultInterceptionCallBack = (response: AxiosResponse) => {
+    const { status, config, request, data: resData } = response
+    const { data: reqData } = config
+    const { _header: reqHeaders, res } = request
+    const { rawHeaders } = res
+
+    // Converts an array of strings into a single string with the following format:
+    // <headerName>: <headerValue>
+    const resHeaders = rawHeaders.reduce(
+      (acc: string, value: string, i: number) => {
+        if (i % 2 === 0) {
+          acc += `${i === 0 ? '' : '\n'}${value}`
+        } else {
+          acc += `: ${value}`
+        }
+
+        return acc
+      },
+      ''
+    )
+
+    const parsedResBody = this.parseInterceptedBody(resData)
+
+    // HTTP response summary.
+    process.logger?.info(`HTTP Request (first 50 lines):
+${reqHeaders}${this.parseInterceptedBody(reqData)}
+
+HTTP Response Code: ${this.prettifyString(status)}
+
+HTTP Response (first 50 lines):
+${resHeaders}${parsedResBody ? `\n\n${parsedResBody}` : ''}
+`)
+
+    return response
+  }
+
+  /**
+   * Turns on verbose mode to log every HTTP response.
+   * @param successCallBack - function that should be triggered on every HTTP response with the status 2**.
+   * @param errorCallBack - function that should be triggered on every HTTP response with the status different from 2**.
+   */
+  public enableVerboseMode = (
+    successCallBack = this.defaultInterceptionCallBack,
+    errorCallBack = this.defaultInterceptionCallBack
+  ) => {
+    this.httpInterceptor = this.httpClient.interceptors.response.use(
+      successCallBack,
+      errorCallBack
+    )
+  }
+
+  /**
+   * Turns off verbose mode to log every HTTP response.
+   */
+  public disableVerboseMode = () => {
+    if (this.httpInterceptor) {
+      this.httpClient.interceptors.response.eject(this.httpInterceptor)
+    }
+  }
+
   protected getHeaders = (
     accessToken: string | undefined,
     contentType: string

src/request/SasjsRequestClient.ts

@@ -1,8 +1,7 @@
 import { RequestClient } from './RequestClient'
 import { AxiosResponse } from 'axios'
-import { SASJS_LOGS_SEPARATOR } from '../utils'
 
-interface SasjsParsedResponse<T> {
+export interface SasjsParsedResponse<T> {
   result: T
   log: string
   etag: string
@@ -45,13 +44,30 @@ export class SasjsRequestClient extends RequestClient {
       }
     } catch {
       if (response.data.includes(SASJS_LOGS_SEPARATOR)) {
-        const splittedResponse = response.data.split(SASJS_LOGS_SEPARATOR)
+        const { data } = response
+        const splittedResponse: string[] = data.split(SASJS_LOGS_SEPARATOR)
 
-        webout = splittedResponse[0]
+        webout = splittedResponse.splice(0, 1)[0]
         if (webout !== undefined) parsedResponse = webout
 
-        log = splittedResponse[1]
-        printOutput = splittedResponse[2]
+        // log can contain nested logs
+        const logs = splittedResponse.splice(0, splittedResponse.length - 1)
+
+        // tests if string ends with SASJS_LOGS_SEPARATOR
+        const endingWithLogSepRegExp = new RegExp(`${SASJS_LOGS_SEPARATOR}$`)
+
+        // at this point splittedResponse can contain only one item
+        const lastChunk = splittedResponse[0]
+
+        if (lastChunk) {
+          // if the last chunk doesn't end with SASJS_LOGS_SEPARATOR, then it is a printOutput
+          // else the last chunk is part of the log and has to be joined
+          if (!endingWithLogSepRegExp.test(data)) printOutput = lastChunk
+          else if (logs.length > 1) logs.push(lastChunk)
+        }
+
+        // join logs into single log with SASJS_LOGS_SEPARATOR
+        log = logs.join(SASJS_LOGS_SEPARATOR)
       } else {
         parsedResponse = response.data
       }
@@ -59,7 +75,7 @@ export class SasjsRequestClient extends RequestClient {
 
     const returnResult: SasjsParsedResponse<T> = {
       result: parsedResponse as T,
-      log,
+      log: log || '',
       etag,
       status: response.status
     }
@@ -69,3 +85,6 @@ export class SasjsRequestClient extends RequestClient {
     return returnResult
   }
 }
+
+export const SASJS_LOGS_SEPARATOR =
+  'SASJS_LOGS_SEPARATOR_163ee17b6ff24f028928972d80a26784'

src/request/spec/SasjsRequestClient.spec.ts

@@ -0,0 +1,172 @@
+import {
+  SASJS_LOGS_SEPARATOR,
+  SasjsRequestClient,
+  SasjsParsedResponse
+} from '../SasjsRequestClient'
+import { AxiosResponse } from 'axios'
+
+describe('SasjsRequestClient', () => {
+  const requestClient = new SasjsRequestClient('')
+  const etag = 'etag'
+  const status = 200
+
+  const webout = `hello`
+  const log = `1                                                          The SAS System                             Tuesday, 25 July 2023 12:51:00
+
+
+PROC MIGRATE will preserve current SAS file attributes and is 
+recommended for converting all your SAS libraries from any 
+SAS 8 release to SAS 9.  For details and examples, please see
+http://support.sas.com/rnd/migration/index.html
+
+
+
+NOTE: SAS initialization used:
+    real time           0.01 seconds
+    cpu time            0.02 seconds
+    
+
+`
+  const printOutput = 'printOutPut'
+
+  describe('parseResponse', () => {})
+
+  it('should parse response with 1 log', () => {
+    const response: AxiosResponse<any> = {
+      data: `${webout}
+${SASJS_LOGS_SEPARATOR}
+${log}
+${SASJS_LOGS_SEPARATOR}`,
+      status,
+      statusText: 'ok',
+      headers: { etag },
+      config: {}
+    }
+
+    const expectedParsedResponse: SasjsParsedResponse<string> = {
+      result: `${webout}
+`,
+      log: `
+${log}
+`,
+      etag,
+      status
+    }
+
+    expect(requestClient['parseResponse'](response)).toEqual(
+      expectedParsedResponse
+    )
+  })
+
+  it('should parse response with 1 log and printOutput', () => {
+    const response: AxiosResponse<any> = {
+      data: `${webout}
+${SASJS_LOGS_SEPARATOR}
+${log}
+${SASJS_LOGS_SEPARATOR}
+${printOutput}`,
+      status,
+      statusText: 'ok',
+      headers: { etag },
+      config: {}
+    }
+
+    const expectedParsedResponse: SasjsParsedResponse<string> = {
+      result: `${webout}
+`,
+      log: `
+${log}
+`,
+      etag,
+      status,
+      printOutput: `
+${printOutput}`
+    }
+
+    expect(requestClient['parseResponse'](response)).toEqual(
+      expectedParsedResponse
+    )
+  })
+
+  it('should parse response with nested logs', () => {
+    const logWithNestedLog = `root log start
+${SASJS_LOGS_SEPARATOR}
+${log}
+${SASJS_LOGS_SEPARATOR}
+root log end`
+
+    const response: AxiosResponse<any> = {
+      data: `${webout}
+${SASJS_LOGS_SEPARATOR}
+${logWithNestedLog}
+${SASJS_LOGS_SEPARATOR}`,
+      status,
+      statusText: 'ok',
+      headers: { etag },
+      config: {}
+    }
+
+    const expectedParsedResponse: SasjsParsedResponse<string> = {
+      result: `${webout}
+`,
+      log: `
+${logWithNestedLog}
+`,
+      etag,
+      status
+    }
+
+    expect(requestClient['parseResponse'](response)).toEqual(
+      expectedParsedResponse
+    )
+  })
+
+  it('should parse response with nested logs and printOutput', () => {
+    const logWithNestedLog = `root log start
+${SASJS_LOGS_SEPARATOR}
+${log}
+${SASJS_LOGS_SEPARATOR}
+log with indentation
+  ${SASJS_LOGS_SEPARATOR}
+  ${log}
+  ${SASJS_LOGS_SEPARATOR}
+some SAS code containing ${SASJS_LOGS_SEPARATOR}
+root log end`
+
+    const response: AxiosResponse<any> = {
+      data: `${webout}
+${SASJS_LOGS_SEPARATOR}
+${logWithNestedLog}
+${SASJS_LOGS_SEPARATOR}
+${printOutput}`,
+      status,
+      statusText: 'ok',
+      headers: { etag },
+      config: {}
+    }
+
+    const expectedParsedResponse: SasjsParsedResponse<string> = {
+      result: `${webout}
+`,
+      log: `
+${logWithNestedLog}
+`,
+      etag,
+      status,
+      printOutput: `
+${printOutput}`
+    }
+
+    expect(requestClient['parseResponse'](response)).toEqual(
+      expectedParsedResponse
+    )
+  })
+})
+
+describe('SASJS_LOGS_SEPARATOR', () => {
+  it('SASJS_LOGS_SEPARATOR should be hardcoded', () => {
+    expect(SASJS_LOGS_SEPARATOR).toEqual(
+      'SASJS_LOGS_SEPARATOR_163ee17b6ff24f028928972d80a26784'
+    )
+  })
+})

src/test/RequestClient.spec.ts

@@ -13,6 +13,8 @@ import {
 } from '../types/errors'
 import { RequestClient } from '../request/RequestClient'
 import { getTokenRequestErrorPrefixResponse } from '../auth/getTokenRequestErrorPrefix'
+import { AxiosResponse } from 'axios'
+import { Logger, LogLevel } from '@sasjs/utils/logger'
 
 const axiosActual = jest.requireActual('axios')
 
@@ -25,16 +27,6 @@ jest
 const PORT = 8000
 const SERVER_URL = `https://localhost:${PORT}/`
 
-const ERROR_MESSAGES = {
-  selfSigned: 'self signed certificate',
-  CCA: 'unable to verify the first certificate'
-}
-
-const incorrectAuthCodeErr = {
-  error: 'unauthorized',
-  error_description: 'Bad credentials'
-}
-
 describe('RequestClient', () => {
   let server: http.Server
 
@@ -80,6 +72,187 @@ describe('RequestClient', () => {
     expect(rejectionErrorMessage).toEqual(expectedError.message)
   })
 
+  describe('defaultInterceptionCallBack', () => {
+    beforeAll(() => {
+      ;(process as any).logger = new Logger(LogLevel.Off)
+    })
+
+    it('should log parsed response', () => {
+      jest.spyOn((process as any).logger, 'info')
+
+      const status = 200
+      const reqData = `{
+        name: 'test_job',
+        description: 'Powered by SASjs',
+        code: ['test_code'],
+        variables: {
+          SYS_JES_JOB_URI: '',
+          _program: '/Public/sasjs/jobs/jobs/test_job'
+        },
+        arguments: {
+          _contextName: 'SAS Job Execution compute context',
+          _OMITJSONLISTING: true,
+          _OMITJSONLOG: true,
+          _OMITSESSIONRESULTS: true,
+          _OMITTEXTLISTING: true,
+          _OMITTEXTLOG: true
+        }
+      }`
+      const resData = {
+        id: 'id_string',
+        name: 'name_string',
+        uri: 'uri_string',
+        createdBy: 'createdBy_string',
+        code: 'TEST CODE',
+        links: [
+          {
+            method: 'method_string',
+            rel: 'state',
+            href: 'state_href_string',
+            uri: 'uri_string',
+            type: 'type_string'
+          },
+          {
+            method: 'method_string',
+            rel: 'state',
+            href: 'state_href_string',
+            uri: 'uri_string',
+            type: 'type_string'
+          },
+          {
+            method: 'method_string',
+            rel: 'state',
+            href: 'state_href_string',
+            uri: 'uri_string',
+            type: 'type_string'
+          },
+          {
+            method: 'method_string',
+            rel: 'state',
+            href: 'state_href_string',
+            uri: 'uri_string',
+            type: 'type_string'
+          },
+          {
+            method: 'method_string',
+            rel: 'state',
+            href: 'state_href_string',
+            uri: 'uri_string',
+            type: 'type_string'
+          },
+          {
+            method: 'method_string',
+            rel: 'self',
+            href: 'self_href_string',
+            uri: 'uri_string',
+            type: 'type_string'
+          }
+        ],
+        results: { '_webout.json': '_webout.json_string' },
+        logStatistics: {
+          lineCount: 1,
+          modifiedTimeStamp: 'modifiedTimeStamp_string'
+        }
+      }
+      const reqHeaders = `POST https://sas.server.com/compute/sessions/session_id/jobs HTTP/1.1
+Accept: application/json
+Content-Type: application/json
+User-Agent: axios/0.27.2
+Content-Length: 334
+host: sas.server.io
+Connection: close
+`
+      const resHeaders = ['content-type', 'application/json']
+      const mockedResponse: AxiosResponse = {
+        data: resData,
+        status,
+        statusText: '',
+        headers: {},
+        config: { data: reqData },
+        request: { _header: reqHeaders, res: { rawHeaders: resHeaders } }
+      }
+
+      const requestClient = new RequestClient('')
+      requestClient['defaultInterceptionCallBack'](mockedResponse)
+
+      const expectedLog = `HTTP Request (first 50 lines):
+${reqHeaders}${requestClient['parseInterceptedBody'](reqData)}
+
+HTTP Response Code: ${requestClient['prettifyString'](status)}
+
+HTTP Response (first 50 lines):
+${resHeaders[0]}: ${resHeaders[1]}${
+        requestClient['parseInterceptedBody'](resData)
+          ? `\n\n${requestClient['parseInterceptedBody'](resData)}`
+          : ''
+      }
+`
+
+      expect((process as any).logger.info).toHaveBeenCalledWith(expectedLog)
+    })
+  })
+
+  describe('enableVerboseMode', () => {
+    it('should add defaultInterceptionCallBack functions to response interceptors', () => {
+      const requestClient = new RequestClient('')
+      const interceptorSpy = jest.spyOn(
+        requestClient['httpClient'].interceptors.response,
+        'use'
+      )
+
+      requestClient.enableVerboseMode()
+
+      expect(interceptorSpy).toHaveBeenCalledWith(
+        requestClient['defaultInterceptionCallBack'],
+        requestClient['defaultInterceptionCallBack']
+      )
+    })
+
+    it('should add callback functions to response interceptors', () => {
+      const requestClient = new RequestClient('')
+      const interceptorSpy = jest.spyOn(
+        requestClient['httpClient'].interceptors.response,
+        'use'
+      )
+
+      const successCallback = (response: AxiosResponse) => {
+        console.log('success')
+
+        return response
+      }
+      const failureCallback = (response: AxiosResponse) => {
+        console.log('failure')
+
+        return response
+      }
+
+      requestClient.enableVerboseMode(successCallback, failureCallback)
+
+      expect(interceptorSpy).toHaveBeenCalledWith(
+        successCallback,
+        failureCallback
+      )
+    })
+  })
+
+  describe('disableVerboseMode', () => {
+    it('should eject interceptor', () => {
+      const requestClient = new RequestClient('')
+
+      const interceptorSpy = jest.spyOn(
+        requestClient['httpClient'].interceptors.response,
+        'eject'
+      )
+
+      const interceptorId = 100
+
+      requestClient['httpInterceptor'] = interceptorId
+      requestClient.disableVerboseMode()
+
+      expect(interceptorSpy).toHaveBeenCalledWith(interceptorId)
+    })
+  })
+
   describe('handleError', () => {
     const requestClient = new RequestClient('https://localhost:8009')
     const randomError = 'some error'

src/utils/constants.ts

@@ -1,2 +0,0 @@
-export const SASJS_LOGS_SEPARATOR =
-  'SASJS_LOGS_SEPARATOR_163ee17b6ff24f028928972d80a26784'

src/utils/index.ts

@@ -2,7 +2,6 @@ export * from './appendExtraResponseAttributes'
 export * from './asyncForEach'
 export * from './compareTimestamps'
 export * from './convertToCsv'
-export * from './constants'
 export * from './createAxiosInstance'
 export * from './delay'
 export * from './fetchLogByChunks'