diff --git a/eng/common/TestResources/New-TestResources.ps1 b/eng/common/TestResources/New-TestResources.ps1 index 4ce8a76d1a43..4bdb301dc853 100644 --- a/eng/common/TestResources/New-TestResources.ps1 +++ b/eng/common/TestResources/New-TestResources.ps1 @@ -325,7 +325,7 @@ $shell, $shellExportFormat = if (($parentProcessName = (Get-Process -Id $PID).Pa } elseif (@('bash', 'csh', 'tcsh', 'zsh') -contains $parentProcessName) { 'shell', 'export {0}={1}' } else { - 'PowerShell', '$env:{0} = ''{1}''' + 'PowerShell', '${{env:{0}}} = ''{1}''' } # Deploy the templates diff --git a/eng/common/TestResources/README.md b/eng/common/TestResources/README.md index 070f2ba49ec5..2e2d72c9b52b 100644 --- a/eng/common/TestResources/README.md +++ b/eng/common/TestResources/README.md @@ -39,14 +39,14 @@ Along with some log messages, this will output environment variables based on your current shell like in the following example: ```powershell -$env:AZURE_TENANT_ID = '<>' -$env:AZURE_CLIENT_ID = '<>' -$env:AZURE_CLIENT_SECRET = '<>' -$env:AZURE_SUBSCRIPTION_ID = 'YOUR SUBSCRIPTION ID' -$env:AZURE_RESOURCE_GROUP = 'rg-myusername' -$env:AZURE_LOCATION = 'westus2' -$env:AZURE_SEARCH_STORAGE_NAME = 'myusernamestg' -$env:AZURE_SEARCH_STORAGE_KEY = '<>' +${env:AZURE_TENANT_ID} = '<>' +${env:AZURE_CLIENT_ID} = '<>' +${env:AZURE_CLIENT_SECRET} = '<>' +${env:AZURE_SUBSCRIPTION_ID} = 'YOUR SUBSCRIPTION ID' +${env:AZURE_RESOURCE_GROUP} = 'rg-myusername' +${env:AZURE_LOCATION} = 'westus2' +${env:AZURE_SEARCH_STORAGE_NAME} = 'myusernamestg' +${env:AZURE_SEARCH_STORAGE_KEY} = '<>' ``` For security reasons we do not set these environment variables automatically @@ -62,14 +62,14 @@ applications started outside the terminal, you could copy and paste the following commands: ```powershell -setx AZURE_TENANT_ID $env:AZURE_TENANT_ID -setx AZURE_CLIENT_ID $env:AZURE_CLIENT_ID -setx AZURE_CLIENT_SECRET $env:AZURE_CLIENT_SECRET -setx AZURE_SUBSCRIPTION_ID $env:AZURE_SUBSCRIPTION_ID -setx AZURE_RESOURCE_GROUP $env:AZURE_RESOURCE_GROUP -setx AZURE_LOCATION $env:AZURE_LOCATION -setx AZURE_SEARCH_STORAGE_NAME $env:AZURE_SEARCH_STORAGE_NAME -setx AZURE_SEARCH_STORAGE_KEY $env:AZURE_SEARCH_STORAGE_KEY +setx AZURE_TENANT_ID ${env:AZURE_TENANT_ID} +setx AZURE_CLIENT_ID ${env:AZURE_CLIENT_ID} +setx AZURE_CLIENT_SECRET ${env:AZURE_CLIENT_SECRET} +setx AZURE_SUBSCRIPTION_ID ${env:AZURE_SUBSCRIPTION_ID} +setx AZURE_RESOURCE_GROUP ${env:AZURE_RESOURCE_GROUP} +setx AZURE_LOCATION ${env:AZURE_LOCATION} +setx AZURE_SEARCH_STORAGE_NAME ${env:AZURE_SEARCH_STORAGE_NAME} +setx AZURE_SEARCH_STORAGE_KEY ${env:AZURE_SEARCH_STORAGE_KEY} ``` After running or recording live tests, if you do not plan on further testing diff --git a/sdk/cognitiveservices/cognitiveservices-computervision/package.json b/sdk/cognitiveservices/cognitiveservices-computervision/package.json index 7b246f48db8a..0837fd2f3ab5 100644 --- a/sdk/cognitiveservices/cognitiveservices-computervision/package.json +++ b/sdk/cognitiveservices/cognitiveservices-computervision/package.json @@ -2,7 +2,7 @@ "name": "@azure/cognitiveservices-computervision", "author": "Microsoft Corporation", "description": "ComputerVisionClient Library with typescript type definitions for node.js and browser.", - "version": "7.0.1", + "version": "7.1.0", "dependencies": { "@azure/ms-rest-js": "^2.0.4", "tslib": "^1.10.0" diff --git a/sdk/cognitiveservices/cognitiveservices-computervision/src/computerVisionClientContext.ts b/sdk/cognitiveservices/cognitiveservices-computervision/src/computerVisionClientContext.ts index 6b32300785d0..2c80d88636c9 100644 --- a/sdk/cognitiveservices/cognitiveservices-computervision/src/computerVisionClientContext.ts +++ b/sdk/cognitiveservices/cognitiveservices-computervision/src/computerVisionClientContext.ts @@ -11,7 +11,7 @@ import * as msRest from "@azure/ms-rest-js"; const packageName = "@azure/cognitiveservices-computervision"; -const packageVersion = "7.0.1"; +const packageVersion = "7.1.0"; export class ComputerVisionClientContext extends msRest.ServiceClient { endpoint: string; @@ -42,7 +42,7 @@ export class ComputerVisionClientContext extends msRest.ServiceClient { super(credentials, options); - this.baseUri = "{Endpoint}/vision/v3.0"; + this.baseUri = "{Endpoint}/vision/v3.1"; this.requestContentType = "application/json; charset=utf-8"; this.endpoint = endpoint; this.credentials = credentials; diff --git a/sdk/cognitiveservices/cognitiveservices-computervision/src/models/index.ts b/sdk/cognitiveservices/cognitiveservices-computervision/src/models/index.ts index bad4b3dba42c..afb87bfce8a3 100644 --- a/sdk/cognitiveservices/cognitiveservices-computervision/src/models/index.ts +++ b/sdk/cognitiveservices/cognitiveservices-computervision/src/models/index.ts @@ -864,12 +864,12 @@ export interface ComputerVisionClientGenerateThumbnailOptionalParams extends msR */ export interface ComputerVisionClientReadOptionalParams extends msRest.RequestOptionsBase { /** - * The BCP-47 language code of the text to be detected in the image. In future versions, when - * language parameter is not passed, language detection will be used to determine the language. - * However, in the current version, missing language parameter will cause English to be used. To - * ensure that your document is always parsed in English without the use of language detection in - * the future, pass “en” in the language parameter. Possible values include: 'en', 'es', 'fr', - * 'de', 'it', 'nl', 'pt'. Default value: 'en'. + * The BCP-47 language code of the text in the document. Currently, only English ('en'), Dutch + * (‘nl’), French (‘fr’), German (‘de’), Italian (‘it’), Portuguese (‘pt), and Spanish ('es') are + * supported. Read supports auto language identification and multi-language documents, so only + * provide a language code if you would like to force the documented to be processed as that + * specific language. Possible values include: 'en', 'es', 'fr', 'de', 'it', 'nl', 'pt'. Default + * value: 'en'. */ language?: OcrDetectionLanguage; } @@ -988,12 +988,12 @@ export interface ComputerVisionClientTagImageInStreamOptionalParams extends msRe */ export interface ComputerVisionClientReadInStreamOptionalParams extends msRest.RequestOptionsBase { /** - * The BCP-47 language code of the text to be detected in the image. In future versions, when - * language parameter is not passed, language detection will be used to determine the language. - * However, in the current version, missing language parameter will cause English to be used. To - * ensure that your document is always parsed in English without the use of language detection in - * the future, pass “en” in the language parameter. Possible values include: 'en', 'es', 'fr', - * 'de', 'it', 'nl', 'pt'. Default value: 'en'. + * The BCP-47 language code of the text in the document. Currently, only English ('en'), Dutch + * (‘nl’), French (‘fr’), German (‘de’), Italian (‘it’), Portuguese (‘pt), and Spanish ('es') are + * supported. Read supports auto language identification and multi-language documents, so only + * provide a language code if you would like to force the documented to be processed as that + * specific language. Possible values include: 'en', 'es', 'fr', 'de', 'it', 'nl', 'pt'. Default + * value: 'en'. */ language?: OcrDetectionLanguage; } diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/Base.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/Base.ts deleted file mode 100644 index 0fcb683c1195..000000000000 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/Base.ts +++ /dev/null @@ -1,18 +0,0 @@ -// THIS FILE WAS AUTOGENERATED - -/** - * Data struct to contain only C section with custom fields. - */ -class Base { - /** - * Name of item (B section) if any. If telemetry data is derived straight from this, this should be null. - */ - public baseType: "RequestData" | "RemoteDependencyData" | undefined; - - public baseData?: { [key: string]: any } = {}; - - public properties: any; - - constructor() {} -} -export = Base; diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/ContextTagKeys.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/ContextTagKeys.ts deleted file mode 100644 index f3ca18247590..000000000000 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/ContextTagKeys.ts +++ /dev/null @@ -1,153 +0,0 @@ -// THIS FILE WAS AUTOGENERATED - -class ContextTagKeys { - /** - * Application version. Information in the application context fields is always about the application that is sending the telemetry. - */ - public applicationVersion: string; - - /** - * Unique client device id. Computer name in most cases. - */ - public deviceId: string; - - /** - * Device locale using - pattern, following RFC 5646. Example 'en-US'. - */ - public deviceLocale: string; - - /** - * Model of the device the end user of the application is using. Used for client scenarios. If this field is empty then it is derived from the user agent. - */ - public deviceModel: string; - - /** - * Client device OEM name taken from the browser. - */ - public deviceOEMName: string; - - /** - * Operating system name and version of the device the end user of the application is using. If this field is empty then it is derived from the user agent. Example 'Windows 10 Pro 10.0.10586.0' - */ - public deviceOSVersion: string; - - /** - * The type of the device the end user of the application is using. Used primarily to distinguish JavaScript telemetry from server side telemetry. Examples: 'PC', 'Phone', 'Browser'. 'PC' is the default value. - */ - public deviceType: string; - - /** - * The IP address of the client device. IPv4 and IPv6 are supported. Information in the location context fields is always about the end user. When telemetry is sent from a service, the location context is about the user that initiated the operation in the service. - */ - public locationIp: string; - - /** - * A unique identifier for the operation instance. The operation.id is created by either a request or a page view. All other telemetry sets this to the value for the containing request or page view. Operation.id is used for finding all the telemetry items for a specific operation instance. - */ - public operationId: string; - - /** - * The name (group) of the operation. The operation.name is created by either a request or a page view. All other telemetry items set this to the value for the containing request or page view. Operation.name is used for finding all the telemetry items for a group of operations (i.e. 'GET Home/Index'). - */ - public operationName: string; - - /** - * The unique identifier of the telemetry item's immediate parent. - */ - public operationParentId: string; - - /** - * Name of synthetic source. Some telemetry from the application may represent a synthetic traffic. It may be web crawler indexing the web site, site availability tests or traces from diagnostic libraries like Application Insights SDK itself. - */ - public operationSyntheticSource: string; - - /** - * The correlation vector is a light weight vector clock which can be used to identify and order related events across clients and services. - */ - public operationCorrelationVector: string; - - /** - * Session ID - the instance of the user's interaction with the app. Information in the session context fields is always about the end user. When telemetry is sent from a service, the session context is about the user that initiated the operation in the service. - */ - public sessionId: string; - - /** - * Boolean value indicating whether the session identified by ai.session.id is first for the user or not. - */ - public sessionIsFirst: string; - - /** - * In multi-tenant applications this is the account ID or name which the user is acting with. Examples may be subscription ID for Azure portal or blog name blogging platform. - */ - public userAccountId: string; - - /** - * Anonymous user id. Represents the end user of the application. When telemetry is sent from a service, the user context is about the user that initiated the operation in the service. - */ - public userId: string; - - /** - * Authenticated user id. The opposite of ai.user.id, this represents the user with a friendly name. Since it's PII information it is not collected by default by most SDKs. - */ - public userAuthUserId: string; - - /** - * Name of the role the application is a part of. For Azure environment, this should be initialized with - * [Microsoft.WindowsAzure.ServiceRuntime.RoleEnvironment]::CurrentRoleInstance.Role.Name - * See more details here: https://dzone.com/articles/accessing-azure-role-0 - * It is recommended that you initialize environment variable with this value during machine startup, and then set context field from environment variable - * appInsights.client.context.tags[appInsights.client.context.keys.cloudRole] = process.env.RoleName - */ - public cloudRole: string; - - /** - * Name of the instance where the application is running. For Azure environment, this should be initialized with - * [Microsoft.WindowsAzure.ServiceRuntime.RoleEnvironment]::CurrentRoleInstance.Id - * See more details here: https://dzone.com/articles/accessing-azure-role-0 - * It is recommended that you initialize environment variable with this value during machine startup, and then set context field from environment variable - * appInsights.client.context.tags[appInsights.client.context.keys.cloudRoleInstance] = process.env.RoleInstanceId - */ - public cloudRoleInstance: string; - - /** - * SDK version. See https://github.com/Microsoft/ApplicationInsights-Home/blob/master/SDK-AUTHORING.md#sdk-version-specification for information. - */ - public internalSdkVersion: string; - - /** - * Agent version. Used to indicate the version of StatusMonitor installed on the computer if it is used for data collection. - */ - public internalAgentVersion: string; - - /** - * This is the node name used for billing purposes. Use it to override the standard detection of nodes. - */ - public internalNodeName: string; - - constructor() { - this.applicationVersion = 'ai.application.ver'; - this.deviceId = 'ai.device.id'; - this.deviceLocale = 'ai.device.locale'; - this.deviceModel = 'ai.device.model'; - this.deviceOEMName = 'ai.device.oemName'; - this.deviceOSVersion = 'ai.device.osVersion'; - this.deviceType = 'ai.device.type'; - this.locationIp = 'ai.location.ip'; - this.operationId = 'ai.operation.id'; - this.operationName = 'ai.operation.name'; - this.operationParentId = 'ai.operation.parentId'; - this.operationSyntheticSource = 'ai.operation.syntheticSource'; - this.operationCorrelationVector = 'ai.operation.correlationVector'; - this.sessionId = 'ai.session.id'; - this.sessionIsFirst = 'ai.session.isFirst'; - this.userAccountId = 'ai.user.accountId'; - this.userId = 'ai.user.id'; - this.userAuthUserId = 'ai.user.authUserId'; - this.cloudRole = 'ai.cloud.role'; - this.cloudRoleInstance = 'ai.cloud.roleInstance'; - this.internalSdkVersion = 'ai.internal.sdkVersion'; - this.internalAgentVersion = 'ai.internal.agentVersion'; - this.internalNodeName = 'ai.internal.nodeName'; - } -} -export = ContextTagKeys; diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/Data.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/Data.ts deleted file mode 100644 index 9df0bf869d73..000000000000 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/Data.ts +++ /dev/null @@ -1,14 +0,0 @@ -// THIS FILE WAS AUTOGENERATED -import Base = require("./Base"); -"use strict"; - -/** - * Data struct to contain both B and C sections. - */ -class Data extends Base { - /** - * Container for data item (B section). - */ - public baseData: TDomain | undefined; -} -export = Data; diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/Domain.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/Domain.ts deleted file mode 100644 index 76c6dbae4228..000000000000 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/Domain.ts +++ /dev/null @@ -1,25 +0,0 @@ -// THIS FILE WAS AUTOGENERATED - -import { Properties, Measurements } from "../../../types"; - -/** - * The abstract common base of all domains. - */ -class Domain { - - /** - * Collection of custom properties. - */ - properties: Properties; - - /** - * Collection of custom measurements. - */ - measurements: Measurements; - - constructor() { - this.properties = {}; - this.measurements = {}; - } -} -export = Domain; diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/index.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/index.ts deleted file mode 100644 index 5a7686fb0f9a..000000000000 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/Generated/index.ts +++ /dev/null @@ -1,6 +0,0 @@ -// THIS FILE WAS AUTOGENERATED - -export import Base = require("./Base"); -export import ContextTagKeys = require("./ContextTagKeys"); -export import Data = require("./Data"); -export import Domain = require("./Domain"); diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/index.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/index.ts index 015d2051a098..86ad2cf489dd 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/index.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/src/Declarations/Contracts/index.ts @@ -1,2 +1 @@ export * from "./Constants"; -export * from "./Generated"; diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/generated/models/index.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/generated/models/index.ts index 992703831040..f447152fd564 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/generated/models/index.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/src/generated/models/index.ts @@ -23,7 +23,7 @@ export interface TelemetryItem { /** * Event date time when telemetry item was created. This is the wall clock time on the client when the event was generated. There is no guarantee that the client's time is accurate. This field must be formatted in UTC ISO 8601 format, with a trailing 'Z' character, as described publicly on https://en.wikipedia.org/wiki/ISO_8601#UTC. Note: the number of decimal seconds digits provided are variable (and unspecified). Consumers should handle this, i.e. managed code consumers should not use format 'O' for parsing as it specifies a fixed length. Example: 2009-06-15T13:45:30.0000000Z. */ - time: string; + time: Date; /** * Sampling rate used in application. This telemetry item represents 1 / sampleRate actual telemetry items. */ diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/generated/models/mappers.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/generated/models/mappers.ts index 1bdd1eded469..95b259922a1c 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/generated/models/mappers.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/src/generated/models/mappers.ts @@ -31,7 +31,7 @@ export const TelemetryItem: coreHttp.CompositeMapper = { serializedName: "time", required: true, type: { - name: "String" + name: "DateTime" } }, sampleRate: { diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/platform/nodejs/context/context.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/platform/nodejs/context/context.ts index fa67c84cc575..1ac4ac5a084e 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/platform/nodejs/context/context.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/src/platform/nodejs/context/context.ts @@ -7,16 +7,15 @@ import * as path from "path"; import { Logger } from "@opentelemetry/api"; import { ConsoleLogger, LogLevel, SDK_INFO } from "@opentelemetry/core"; -import * as Contracts from "../../../Declarations/Contracts"; +import { ContextTagKeys } from "../../../generated"; +import { Tags } from "../../../types"; type PackageJson = { version: string }; let instance: Context | null = null; export class Context { - public keys: Contracts.ContextTagKeys; - - public tags: { [key: string]: string }; + public tags: Tags; public static DefaultRoleName: string = "Node.js"; @@ -52,8 +51,7 @@ export class Context { */ private _appPrefix = "../../../" ) { - this.keys = new Contracts.ContextTagKeys(); - this.tags = {} as { [key: string]: string }; + this.tags = {}; this._loadApplicationContext(); this._loadDeviceContext(); @@ -94,19 +92,19 @@ export class Context { Context.appVersion[packageJsonPath] = packageJson.version; } - this.tags[this.keys.applicationVersion] = Context.appVersion[packageJsonPath]; + this.tags["ai.application.ver"] = Context.appVersion[packageJsonPath]; } } private _loadDeviceContext(): void { - this.tags[this.keys.deviceId] = ""; - this.tags[this.keys.cloudRoleInstance] = os && os.hostname(); - this.tags[this.keys.deviceOSVersion] = os && `${os.type()} ${os.release()}`; - this.tags[this.keys.cloudRole] = Context.DefaultRoleName; + this.tags["ai.device.id"] = ""; + this.tags["ai.cloud.role"] = Context.DefaultRoleName; + this.tags["ai.cloud.roleInstance"] = os && os.hostname(); + this.tags["ai.device.osVersion"] = os && `${os.type()} ${os.release()}`; // not yet supported tags - this.tags["ai.device.osArchitecture"] = os && os.arch(); - this.tags["ai.device.osPlatform"] = os && os.platform(); + this.tags["ai.device.osArchitecture" as ContextTagKeys] = os && os.arch(); + this.tags["ai.device.osPlatform" as ContextTagKeys] = os && os.platform(); } private _loadInternalContext(): void { @@ -148,7 +146,7 @@ export class Context { } this.tags[ - this.keys.internalSdkVersion + "ai.internal.sdkVersion" ] = `node${Context.nodeVersion}:ot${SDK_INFO.VERSION}:ext${Context.sdkVersion}`; } } diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/types.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/types.ts index c2afb7249b7c..e272b99d8151 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/types.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/src/types.ts @@ -2,9 +2,9 @@ // Licensed under the MIT license. import { ExportResult } from "@opentelemetry/core"; -import { TelemetryItem as Envelope } from "./generated"; +import { ContextTagKeys, TelemetryItem as Envelope } from "./generated"; -export type Tags = { [key: string]: string }; +export type Tags = { [key in ContextTagKeys]: string }; export type PropertyType = string | number | boolean | object | Array; export type Properties = { [key: string]: Properties | PropertyType }; export interface MSLink { diff --git a/sdk/monitor/monitor-opentelemetry-exporter/src/utils/spanUtils.ts b/sdk/monitor/monitor-opentelemetry-exporter/src/utils/spanUtils.ts index f65b0e370685..de99dd664ec9 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/src/utils/spanUtils.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/src/utils/spanUtils.ts @@ -197,7 +197,7 @@ export function readableSpanToEnvelope( const sampleRate = 100; let baseData: RemoteDependencyData | RequestData; - const time = new Date(hrTimeToMilliseconds(span.startTime)).toISOString(); + const time = new Date(hrTimeToMilliseconds(span.startTime)); const instrumentationKey = ikey; const tags = createTagsFromSpan(span); const [properties, measurements] = createPropertiesFromSpan(span); diff --git a/sdk/monitor/monitor-opentelemetry-exporter/test/common/assert.ts b/sdk/monitor/monitor-opentelemetry-exporter/test/common/assert.ts index 10b7a2d012cd..df97ffafc285 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/test/common/assert.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/test/common/assert.ts @@ -2,18 +2,16 @@ // Licensed under the MIT license. import * as assert from "assert"; -import { Base } from "../../src/Declarations/Contracts"; import { AI_OPERATION_ID, AI_OPERATION_PARENT_ID } from "../../src/utils/constants/applicationinsights"; import { Expectation } from "./scenario/types"; -import { RequestData, TelemetryItem as Envelope } from "../../src/generated"; +import { MonitorBase, RequestData, TelemetryItem as Envelope } from "../../src/generated"; import { TelemetryItem as EnvelopeMapper } from "../../src/generated/models/mappers"; -export const assertData = (actual: Base, expected: Base): void => { +export const assertData = (actual: MonitorBase, expected: MonitorBase): void => { assert.strictEqual(actual.baseType, expected.baseType); - assert.strictEqual(actual.properties, expected.properties); if (expected.baseData) { assert.ok(actual.baseData); @@ -98,7 +96,7 @@ export const assertExpectation = (actual: Envelope[], expectations: Expectation[ break; case "data": if (envelope[0].data) { - assertData(envelope[0].data as Base, value as Base); + assertData(envelope[0].data, value as MonitorBase); } break; default: diff --git a/sdk/monitor/monitor-opentelemetry-exporter/test/unit/export/export.test.ts b/sdk/monitor/monitor-opentelemetry-exporter/test/unit/export/export.test.ts index 47e7644170a4..f17f638fea11 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/test/unit/export/export.test.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/test/unit/export/export.test.ts @@ -50,7 +50,7 @@ describe("#AzureMonitorBaseExporter", () => { const scope = nock(DEFAULT_BREEZE_ENDPOINT).post("/v2/track"); const envelope = { name: "Name", - time: new Date().toISOString() + time: new Date() }; before(() => { @@ -167,11 +167,11 @@ describe("#AzureMonitorBaseExporter", () => { it("should filter envelopes", () => { const fooEnvelope = { name: "foo", - time: new Date().toISOString() + time: new Date() }; const barEnvelope = { name: "bar", - time: new Date().toISOString() + time: new Date() }; const exporter = new TestExporter(); @@ -188,11 +188,11 @@ describe("#AzureMonitorBaseExporter", () => { it("should filter modified envelopes", () => { const fooEnvelope = { name: "foo", - time: new Date().toISOString() + time: new Date() }; const barEnvelope = { name: "bar", - time: new Date().toISOString() + time: new Date() }; const exporter = new TestExporter(); diff --git a/sdk/monitor/monitor-opentelemetry-exporter/test/unit/platform/nodejs/httpSender.test.ts b/sdk/monitor/monitor-opentelemetry-exporter/test/unit/platform/nodejs/httpSender.test.ts index ff17e178ce55..2bdc5772aa97 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/test/unit/platform/nodejs/httpSender.test.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/test/unit/platform/nodejs/httpSender.test.ts @@ -31,7 +31,7 @@ describe("HttpSender", () => { describe("#send()", () => { const envelope: Envelope = { name: "name", - time: new Date().toISOString() + time: new Date() }; it("should send a valid envelope", async () => { const sender = new HttpSender(); diff --git a/sdk/monitor/monitor-opentelemetry-exporter/test/unit/platform/nodejs/persist/fileSystemPersist.test.ts b/sdk/monitor/monitor-opentelemetry-exporter/test/unit/platform/nodejs/persist/fileSystemPersist.test.ts index 8cbd5783c869..db87bb771c4e 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/test/unit/platform/nodejs/persist/fileSystemPersist.test.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/test/unit/platform/nodejs/persist/fileSystemPersist.test.ts @@ -75,7 +75,7 @@ describe("FileSystemPersist", () => { it("should store to disk the value provided", async () => { const envelope: Envelope = { name: "name", - time: new Date().toISOString() + time: new Date() }; const persister = new FileSystemPersist({ instrumentationKey }); const envelopes = [envelope]; diff --git a/sdk/monitor/monitor-opentelemetry-exporter/test/unit/utils/spanUtils.test.ts b/sdk/monitor/monitor-opentelemetry-exporter/test/unit/utils/spanUtils.test.ts index 7241d1be2c69..34c79e3029b8 100644 --- a/sdk/monitor/monitor-opentelemetry-exporter/test/unit/utils/spanUtils.test.ts +++ b/sdk/monitor/monitor-opentelemetry-exporter/test/unit/utils/spanUtils.test.ts @@ -46,7 +46,7 @@ function assertEnvelope( assert.ok(envelope.data); if (expectedTime) { - assert.strictEqual(envelope.time, expectedTime.toISOString()); + assert.deepStrictEqual(envelope.time, expectedTime); } assert.deepStrictEqual(envelope.tags, { ...context.tags, ...expectedTags }); diff --git a/sdk/servicebus/service-bus/src/connectionContext.ts b/sdk/servicebus/service-bus/src/connectionContext.ts index 9e102393d5b4..411af073362c 100644 --- a/sdk/servicebus/service-bus/src/connectionContext.ts +++ b/sdk/servicebus/service-bus/src/connectionContext.ts @@ -1,7 +1,7 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT license. -import { logger } from "./log"; +import { connectionLogger as logger } from "./log"; import { packageJsonInfo } from "./util/constants"; import { ConnectionConfig, @@ -20,7 +20,6 @@ import { MessageReceiver } from "./core/messageReceiver"; import { ManagementClient } from "./core/managementClient"; import { formatUserAgentPrefix } from "./util/utils"; import { getRuntimeInfo } from "./util/runtimeInfo"; -import { logError } from "./util/errors"; /** * @internal @@ -274,20 +273,18 @@ export namespace ConnectionContext { const connectionError = context.connection && context.connection.error ? context.connection.error : undefined; if (connectionError) { - logError( + logger.logError( connectionError, - "[%s] Error (context.connection.error) occurred on the amqp connection: %O", - connectionContext.connection.id, - connectionError + "[%s] Error (context.connection.error) occurred on the amqp connection", + connectionContext.connection.id ); } const contextError = context.error; if (contextError) { - logError( + logger.logError( contextError, - "[%s] Error (context.error) occurred on the amqp connection: %O", - connectionContext.connection.id, - contextError + "[%s] Error (context.error) occurred on the amqp connection", + connectionContext.connection.id ); } const state: Readonly<{ @@ -335,12 +332,11 @@ export namespace ConnectionContext { ); detachCalls.push( sender.onDetached().catch((err) => { - logError( + logger.logError( err, - "[%s] An error occurred while calling onDetached() the sender '%s': %O.", + "[%s] An error occurred while calling onDetached() the sender '%s'", connectionContext.connection.id, - sender.name, - err + sender.name ); }) ); @@ -381,13 +377,12 @@ export namespace ConnectionContext { receiver .onDetached(connectionError || contextError, causedByDisconnect) .catch((err) => { - logError( + logger.logError( err, - "[%s] An error occurred while calling onDetached() on the %s receiver '%s': %O.", + "[%s] An error occurred while calling onDetached() on the %s receiver '%s'", connectionContext.connection.id, receiver.receiverType, - receiver.name, - err + receiver.name ); }) ); @@ -400,38 +395,34 @@ export namespace ConnectionContext { const protocolError: OnAmqpEvent = async (context: EventContext) => { if (context.connection && context.connection.error) { - logError( + logger.logError( context.connection.error, - "[%s] Error (context.connection.error) occurred on the amqp connection: %O", - connectionContext.connection.id, - context.connection.error + "[%s] Error (context.connection.error) occurred on the amqp connection", + connectionContext.connection.id ); } if (context.error) { - logError( + logger.logError( context.error, - "[%s] Error (context.error) occurred on the amqp connection: %O", - connectionContext.connection.id, - context.error + "[%s] Error (context.error) occurred on the amqp connection", + connectionContext.connection.id ); } }; const error: OnAmqpEvent = async (context: EventContext) => { if (context.connection && context.connection.error) { - logError( + logger.logError( context.connection.error, - "[%s] Error (context.connection.error) occurred on the amqp connection: %O", - connectionContext.connection.id, - context.connection && context.connection.error + "[%s] Error (context.connection.error) occurred on the amqp connection", + connectionContext.connection.id ); } if (context.error) { - logError( + logger.logError( context.error, - "[%s] Error (context.error) occurred on the amqp connection: %O", - connectionContext.connection.id, - context.error + "[%s] Error (context.error) occurred on the amqp connection", + connectionContext.connection.id ); } }; @@ -441,10 +432,9 @@ export namespace ConnectionContext { try { await cleanConnectionContext(connectionContext); } catch (err) { - logError( + logger.logError( err, - `[${connectionContext.connectionId}] There was an error closing the connection before reconnecting: %O`, - err + `[${connectionContext.connectionId}] There was an error closing the connection before reconnecting` ); } // Create a new connection, id, locks, and cbs client. @@ -525,7 +515,7 @@ export namespace ConnectionContext { } } catch (err) { const errObj = err instanceof Error ? err : new Error(JSON.stringify(err)); - logError( + logger.logError( err, `An error occurred while closing the connection "${context.connectionId}":\n${errObj}` ); diff --git a/sdk/servicebus/service-bus/src/core/autoLockRenewer.ts b/sdk/servicebus/service-bus/src/core/autoLockRenewer.ts index 26f9a52b7b64..495acd4b6933 100644 --- a/sdk/servicebus/service-bus/src/core/autoLockRenewer.ts +++ b/sdk/servicebus/service-bus/src/core/autoLockRenewer.ts @@ -2,9 +2,8 @@ // Licensed under the MIT license. import { ConnectionContext } from "../connectionContext"; -import { logger } from "../log"; +import { receiverLogger as logger } from "../log"; import { ServiceBusMessageImpl } from "../serviceBusMessage"; -import { logError } from "../util/errors"; import { calculateRenewAfterDuration } from "../util/utils"; import { LinkEntity } from "./linkEntity"; import { OnError } from "./messageReceiver"; @@ -193,7 +192,7 @@ export class LockRenewer { autoRenewLockTask(); } catch (err) { - logError( + logger.logError( err, `${logPrefix} An error occurred while auto renewing the message lock '${bMessage.lockToken}' for message with id '${bMessage.messageId}'` ); diff --git a/sdk/servicebus/service-bus/src/core/batchingReceiver.ts b/sdk/servicebus/service-bus/src/core/batchingReceiver.ts index 4d0c17db8b69..28d57e4cbaef 100644 --- a/sdk/servicebus/service-bus/src/core/batchingReceiver.ts +++ b/sdk/servicebus/service-bus/src/core/batchingReceiver.ts @@ -1,7 +1,7 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT license. -import { logger } from "../log"; +import { receiverLogger as logger } from "../log"; import { MessagingError, translate } from "@azure/core-amqp"; import { AmqpError, @@ -15,7 +15,7 @@ import { import { InternalReceiveMode, ServiceBusMessageImpl } from "../serviceBusMessage"; import { MessageReceiver, OnAmqpEventAsPromise, ReceiveOptions } from "./messageReceiver"; import { ConnectionContext } from "../connectionContext"; -import { logError, throwErrorIfConnectionClosed } from "../util/errors"; +import { throwErrorIfConnectionClosed } from "../util/errors"; import { AbortSignalLike } from "@azure/abort-controller"; import { checkAndRegisterWithAbortSignal } from "../util/utils"; @@ -36,7 +36,7 @@ export class BatchingReceiver extends MessageReceiver { * @param {ReceiveOptions} [options] Options for how you'd like to connect. */ constructor(context: ConnectionContext, entityPath: string, options: ReceiveOptions) { - super(context, entityPath, "br", options); + super(context, entityPath, "batching", options); this._batchingReceiverLite = new BatchingReceiverLite( context, @@ -114,7 +114,7 @@ export class BatchingReceiver extends MessageReceiver { try { logger.verbose( "[%s] Receiver '%s', setting max concurrent calls to 0.", - this._context.connectionId, + this.logPrefix, this.name ); @@ -136,13 +136,7 @@ export class BatchingReceiver extends MessageReceiver { return messages; } catch (error) { - logError( - error, - "[%s] Receiver '%s': Rejecting receiveMessages() with error %O: ", - this._context.connectionId, - this.name, - error - ); + logger.logError(error, "[%s] Rejecting receiveMessages()", this.logPrefix); throw error; } } @@ -338,10 +332,9 @@ export class BatchingReceiverLite { if (error) { error = translate(error); - logError( + logger.logError( error, - `${loggingPrefix} '${eventType}' event occurred. Received an error:\n%O`, - error + `${loggingPrefix} '${eventType}' event occurred. Received an error` ); } else { error = new MessagingError("An error occurred while receiving messages."); @@ -419,10 +412,9 @@ export class BatchingReceiverLite { } } catch (err) { const errObj = err instanceof Error ? err : new Error(JSON.stringify(err)); - logError( + logger.logError( err, - `${loggingPrefix} Received an error while converting AmqpMessage to ServiceBusMessage:\n%O`, - errObj + `${loggingPrefix} Received an error while converting AmqpMessage to ServiceBusMessage` ); reject(errObj); } @@ -436,11 +428,7 @@ export class BatchingReceiverLite { const error = context.session?.error || context.receiver?.error; if (error) { - logError( - error, - `${loggingPrefix} '${type}' event occurred. The associated error is: %O`, - error - ); + logger.logError(error, `${loggingPrefix} '${type}' event occurred. The associated error`); } }; diff --git a/sdk/servicebus/service-bus/src/core/linkEntity.ts b/sdk/servicebus/service-bus/src/core/linkEntity.ts index 14ac8b461e49..6fd6b9d16a62 100644 --- a/sdk/servicebus/service-bus/src/core/linkEntity.ts +++ b/sdk/servicebus/service-bus/src/core/linkEntity.ts @@ -11,7 +11,6 @@ import { MessagingError } from "@azure/core-amqp"; import { ConnectionContext } from "../connectionContext"; -import { logger } from "../log"; import { AwaitableSender, AwaitableSenderOptions, @@ -22,7 +21,7 @@ import { } from "rhea-promise"; import { getUniqueName, StandardAbortMessage } from "../util/utils"; import { AbortError, AbortSignalLike } from "@azure/abort-controller"; -import { logError } from "../util/errors"; +import { ServiceBusLogger } from "../log"; /** * @internal @@ -58,9 +57,9 @@ export interface RequestResponseLinkOptions { * @ignore */ export type ReceiverType = - | "br" // batching receiver - | "sr" // streaming receiver; - | "ms"; // message session + | "batching" // batching receiver + | "streaming" // streaming receiver; + | "session"; // message session /** * @internal @@ -85,9 +84,9 @@ type LinkTypeT< > = LinkT extends Receiver ? ReceiverType : LinkT extends AwaitableSender - ? "s" // sender + ? "sender" // sender : LinkT extends RequestResponseLink - ? "m" // management link + ? "mgmt" // management link : never; /** @@ -186,6 +185,7 @@ export abstract class LinkEntity, + private _logger: ServiceBusLogger, options?: LinkEntityOptions ) { if (!options) options = {}; @@ -202,7 +202,7 @@ export abstract class LinkEntity { - logger.verbose(`${this._logPrefix} Lock ${this._openLock} acquired for initializing link`); + this._logger.verbose( + `${this._logPrefix} Lock ${this._openLock} acquired for initializing link` + ); return this._initLinkImpl(options, abortSignal); }); } @@ -244,16 +246,18 @@ export abstract class LinkEntity { - logger.verbose( + this._logger.verbose( `${this._logPrefix} Attempting to acquire lock token ${this._openLock} for closing link` ); return defaultLock.acquire(this._openLock, () => { - logger.verbose(`${this._logPrefix} Lock ${this._openLock} acquired for closing link`); + this._logger.verbose(`${this._logPrefix} Lock ${this._openLock} acquired for closing link`); return this.closeLinkImpl(); }); } private async closeLinkImpl(): Promise { - logger.verbose(`${this._logPrefix} closeLinkImpl() called`); + this._logger.verbose(`${this._logPrefix} closeLinkImpl() called`); clearTimeout(this._tokenRenewalTimer as NodeJS.Timer); this._tokenRenewalTimer = undefined; @@ -355,9 +359,9 @@ export abstract class LinkEntity} Promise */ private async _negotiateClaim(setTokenRenewal?: boolean): Promise { - logger.verbose(`${this._logPrefix} negotiateclaim() has been called`); + this._logger.verbose(`${this._logPrefix} negotiateclaim() has been called`); // Wait for the connectionContext to be ready to open the link. this.checkIfConnectionReady(); @@ -397,10 +401,10 @@ export abstract class LinkEntity { * "$management" client. */ constructor(context: ConnectionContext, entityPath: string, options?: ManagementClientOptions) { - super(`${entityPath}/$management`, entityPath, context, "m", { + super(`${entityPath}/$management`, entityPath, context, "mgmt", managementClientLogger, { address: options && options.address ? options.address : Constants.management, audience: options && options.audience @@ -227,14 +226,10 @@ export class ManagementClient extends LinkEntity { name: this.replyTo, target: { address: this.replyTo }, onSessionError: (context: EventContext) => { - const id = context.connection.options.id; const ehError = translate(context.session!.error!); - logError( + managementClientLogger.logError( ehError, - "[%s] An error occurred on the session for request/response links for " + - "$management: %O", - id, - ehError + `${this.logPrefix} An error occurred on the session for request/response links for $management` ); } }; @@ -249,32 +244,24 @@ export class ManagementClient extends LinkEntity { ); this.link!.sender.on(SenderEvents.senderError, (context: EventContext) => { - const id = context.connection.options.id; const ehError = translate(context.sender!.error!); - logError( + managementClientLogger.logError( ehError, - "[%s] An error occurred on the $management sender link.. %O", - id, - ehError + `${this.logPrefix} An error occurred on the $management sender link` ); }); this.link!.receiver.on(ReceiverEvents.receiverError, (context: EventContext) => { - const id = context.connection.options.id; const ehError = translate(context.receiver!.error!); - logError( + managementClientLogger.logError( ehError, - "[%s] An error occurred on the $management receiver link.. %O", - id, - ehError + `${this.logPrefix} An error occurred on the $management receiver link` ); }); } catch (err) { err = translate(err); - logError( + managementClientLogger.logError( err, - "[%s] An error occured while establishing the $management links: %O", - this._context.connectionId, - err + `${this.logPrefix} An error occured while establishing the $management links` ); throw err; } @@ -299,6 +286,7 @@ export class ManagementClient extends LinkEntity { private async _makeManagementRequest( request: AmqpMessage, + internalLogger: ServiceBusLogger, sendRequestOptions: SendManagementRequestOptions = {} ): Promise { const retryTimeoutInMs = @@ -316,10 +304,7 @@ export class ManagementClient extends LinkEntity { const waitTimer = setTimeout(actionAfterTimeout, retryTimeoutInMs); - logger.verbose( - "[%s] Acquiring lock to get the management req res link.", - this._context.connectionId - ); + internalLogger.verbose(`${this.logPrefix} Acquiring lock to get the management req res link.`); try { if (!this.isOpen()) { @@ -339,11 +324,11 @@ export class ManagementClient extends LinkEntity { return await this.link!.sendRequest(request, sendRequestOptions); } catch (err) { err = translate(err); - logError( + internalLogger.logError( err, - "[%s] An error occurred during send on management request-response link with address " + + "%s An error occurred during send on management request-response link with address " + "'%s': %O", - this._context.connectionId, + this.logPrefix, this.address, err ); @@ -365,13 +350,11 @@ export class ManagementClient extends LinkEntity { // the other links do. When we add handling of this (via the onDetached call, like other links) // we can change this back to closeLink("permanent"). await this.closeLink(); - logger.verbose("Successfully closed the management session."); + managementClientLogger.verbose("Successfully closed the management session."); } catch (err) { - logError( + managementClientLogger.logError( err, - "[%s] An error occurred while closing the management session: %O.", - this._context.connectionId, - err + `${this.logPrefix} An error occurred while closing the management session` ); throw err; } @@ -481,13 +464,16 @@ export class ManagementClient extends LinkEntity { request.application_properties![Constants.associatedLinkName] = options?.associatedLinkName; } request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose( - "[%s] Peek by sequence number request body: %O.", - this._context.connectionId, + + // TODO: it'd be nice to attribute this peek request to the actual receiver that made it. So have them pass in a + // log prefix rather than just falling back to the management links. + receiverLogger.verbose( + "%s Peek by sequence number request body: %O.", + this.logPrefix, request.body ); - const result = await this._makeManagementRequest(request, options); + const result = await this._makeManagementRequest(request, receiverLogger, options); if (result.application_properties!.statusCode !== 204) { const messages = result.body.messages as { message: Buffer }[]; for (const msg of messages) { @@ -500,11 +486,9 @@ export class ManagementClient extends LinkEntity { } } catch (err) { const error = translate(err) as MessagingError; - logError( + receiverLogger.logError( error, - "An error occurred while sending the request to peek messages to " + - "$management endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the request to peek messages to $management endpoint` ); // statusCode == 404 then do not throw if (error.code !== ConditionErrorNameMapper["com.microsoft:message-not-found"]) { @@ -552,8 +536,12 @@ export class ManagementClient extends LinkEntity { if (options.associatedLinkName) { request.application_properties![Constants.associatedLinkName] = options.associatedLinkName; } - logger.verbose("[%s] Renew message Lock request: %O.", this._context.connectionId, request); - const result = await this._makeManagementRequest(request, { + receiverLogger.verbose( + "[%s] Renew message Lock request: %O.", + this._context.connectionId, + request + ); + const result = await this._makeManagementRequest(request, receiverLogger, { abortSignal: options?.abortSignal, requestName: "renewLock" }); @@ -561,10 +549,9 @@ export class ManagementClient extends LinkEntity { return lockedUntilUtc; } catch (err) { const error = translate(err); - logError( + receiverLogger.logError( error, - "An error occurred while sending the renew lock request to $management " + "endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the renew lock request to $management endpoint` ); throw error; } @@ -619,11 +606,9 @@ export class ManagementClient extends LinkEntity { } else { error = translate(err); } - logError( + senderLogger.logError( error, - "An error occurred while encoding the item at position %d in the messages array" + ": %O", - i, - error + `${this.logPrefix} An error occurred while encoding the item at position ${i} in the messages array` ); throw error; } @@ -640,12 +625,8 @@ export class ManagementClient extends LinkEntity { request.application_properties![Constants.associatedLinkName] = options?.associatedLinkName; } request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose( - "[%s] Schedule messages request body: %O.", - this._context.connectionId, - request.body - ); - const result = await this._makeManagementRequest(request, options); + senderLogger.verbose("%s Schedule messages request body: %O.", this.logPrefix, request.body); + const result = await this._makeManagementRequest(request, senderLogger, options); const sequenceNumbers = result.body[Constants.sequenceNumbers]; const sequenceNumbersAsLong = []; for (let i = 0; i < sequenceNumbers.length; i++) { @@ -658,11 +639,9 @@ export class ManagementClient extends LinkEntity { return sequenceNumbersAsLong; } catch (err) { const error = translate(err); - logError( + senderLogger.logError( error, - "An error occurred while sending the request to schedule messages to " + - "$management endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the request to schedule messages to $management endpoint` ); throw error; } @@ -686,12 +665,9 @@ export class ManagementClient extends LinkEntity { messageBody[Constants.sequenceNumbers].push(Buffer.from(sequenceNumber.toBytesBE())); } catch (err) { const error = translate(err); - logError( + senderLogger.logError( error, - "An error occurred while encoding the item at position %d in the " + - "sequenceNumbers array: %O", - i, - error + `${this.logPrefix} An error occurred while encoding the item at position ${i} in the sequenceNumbers array` ); throw error; } @@ -715,21 +691,19 @@ export class ManagementClient extends LinkEntity { request.application_properties![Constants.associatedLinkName] = options?.associatedLinkName; } request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose( - "[%s] Cancel scheduled messages request body: %O.", - this._context.connectionId, + senderLogger.verbose( + "%s Cancel scheduled messages request body: %O.", + this.logPrefix, request.body ); - await this._makeManagementRequest(request, options); + await this._makeManagementRequest(request, senderLogger, options); return; } catch (err) { const error = translate(err); - logError( + senderLogger.logError( error, - "An error occurred while sending the request to cancel the scheduled message to " + - "$management endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the request to cancel the scheduled message to $management endpoint` ); throw error; } @@ -762,12 +736,9 @@ export class ManagementClient extends LinkEntity { messageBody[Constants.sequenceNumbers].push(Buffer.from(sequenceNumber.toBytesBE())); } catch (err) { const error = translate(err); - logError( + receiverLogger.logError( error, - "An error occurred while encoding the item at position %d in the " + - "sequenceNumbers array: %O", - i, - error + `${this.logPrefix} An error occurred while encoding the item at position ${i} in the sequenceNumbers array` ); throw error; } @@ -796,13 +767,13 @@ export class ManagementClient extends LinkEntity { request.application_properties![Constants.associatedLinkName] = options?.associatedLinkName; } request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose( - "[%s] Receive deferred messages request body: %O.", - this._context.connectionId, + receiverLogger.verbose( + "%s Receive deferred messages request body: %O.", + this.logPrefix, request.body ); - const result = await this._makeManagementRequest(request, options); + const result = await this._makeManagementRequest(request, receiverLogger, options); const messages = result.body.messages as { message: Buffer; "lock-token": Buffer; @@ -822,11 +793,9 @@ export class ManagementClient extends LinkEntity { return messageList; } catch (err) { const error = translate(err); - logError( + receiverLogger.logError( error, - "An error occurred while sending the request to receive deferred messages to " + - "$management endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the request to receive deferred messages to $management endpoint` ); throw error; } @@ -885,19 +854,17 @@ export class ManagementClient extends LinkEntity { request.application_properties![Constants.associatedLinkName] = options.associatedLinkName; } request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose( - "[%s] Update disposition status request body: %O.", - this._context.connectionId, + receiverLogger.verbose( + "%s Update disposition status request body: %O.", + this.logPrefix, request.body ); - await this._makeManagementRequest(request, options); + await this._makeManagementRequest(request, receiverLogger, options); } catch (err) { const error = translate(err); - logError( + receiverLogger.logError( error, - "An error occurred while sending the request to update disposition status to " + - "$management endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the request to update disposition status to $management endpoint` ); throw error; } @@ -929,26 +896,25 @@ export class ManagementClient extends LinkEntity { if (options?.associatedLinkName) { request.application_properties![Constants.associatedLinkName] = options?.associatedLinkName; } - logger.verbose( - "[%s] Renew Session Lock request body: %O.", - this._context.connectionId, + receiverLogger.verbose( + "%s Renew Session Lock request body: %O.", + this.logPrefix, request.body ); - const result = await this._makeManagementRequest(request, options); + const result = await this._makeManagementRequest(request, receiverLogger, options); const lockedUntilUtc = new Date(result.body.expiration); - logger.verbose( - "[%s] Lock for session '%s' will expire at %s.", - this._context.connectionId, + receiverLogger.verbose( + "%s Lock for session '%s' will expire at %s.", + this.logPrefix, sessionId, lockedUntilUtc.toString() ); return lockedUntilUtc; } catch (err) { const error = translate(err); - logError( + receiverLogger.logError( error, - "An error occurred while sending the renew lock request to $management " + "endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the renew lock request to $management endpoint` ); throw error; } @@ -983,18 +949,17 @@ export class ManagementClient extends LinkEntity { request.application_properties![Constants.associatedLinkName] = options?.associatedLinkName; } request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose( - "[%s] Set Session state request body: %O.", - this._context.connectionId, + receiverLogger.verbose( + "%s Set Session state request body: %O.", + this.logPrefix, request.body ); - await this._makeManagementRequest(request, options); + await this._makeManagementRequest(request, receiverLogger, options); } catch (err) { const error = translate(err); - logError( + receiverLogger.logError( error, - "An error occurred while sending the renew lock request to $management " + "endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the renew lock request to $management endpoint` ); throw error; } @@ -1025,21 +990,20 @@ export class ManagementClient extends LinkEntity { request.application_properties![Constants.associatedLinkName] = options?.associatedLinkName; } request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose( - "[%s] Get session state request body: %O.", - this._context.connectionId, + receiverLogger.verbose( + "%s Get session state request body: %O.", + this.logPrefix, request.body ); - const result = await this._makeManagementRequest(request, options); + const result = await this._makeManagementRequest(request, receiverLogger, options); return result.body["session-state"] ? this._context.dataTransformer.decode(result.body["session-state"]) : result.body["session-state"]; } catch (err) { const error = translate(err); - logError( + receiverLogger.logError( error, - "An error occurred while sending the renew lock request to $management " + "endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the renew lock request to $management endpoint` ); throw error; } @@ -1085,20 +1049,19 @@ export class ManagementClient extends LinkEntity { } }; request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose( - "[%s] List sessions request body: %O.", - this._context.connectionId, + managementClientLogger.verbose( + "%s List sessions request body: %O.", + this.logPrefix, request.body ); - const response = await this._makeManagementRequest(request, options); + const response = await this._makeManagementRequest(request, managementClientLogger, options); return (response && response.body && response.body["sessions-ids"]) || []; } catch (err) { const error = translate(err); - logError( + managementClientLogger.logError( error, - "An error occurred while sending the renew lock request to $management " + "endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the renew lock request to $management endpoint` ); throw error; } @@ -1125,8 +1088,12 @@ export class ManagementClient extends LinkEntity { }; request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose("[%s] Get rules request body: %O.", this._context.connectionId, request.body); - const response = await this._makeManagementRequest(request, options); + managementClientLogger.verbose( + "%s Get rules request body: %O.", + this.logPrefix, + request.body + ); + const response = await this._makeManagementRequest(request, managementClientLogger, options); if ( response.application_properties!.statusCode === 204 || !response.body || @@ -1182,8 +1149,8 @@ export class ManagementClient extends LinkEntity { }; break; default: - logger.warning( - `Found unexpected descriptor code for the filter: ${filtersRawData.descriptor.value}` + managementClientLogger.warning( + `${this.logPrefix} Found unexpected descriptor code for the filter: ${filtersRawData.descriptor.value}` ); break; } @@ -1202,10 +1169,9 @@ export class ManagementClient extends LinkEntity { return rules; } catch (err) { const error = translate(err); - logError( + managementClientLogger.logError( error, - "An error occurred while sending the get rules request to $management " + "endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the get rules request to $management endpoint` ); throw error; } @@ -1236,18 +1202,17 @@ export class ManagementClient extends LinkEntity { }; request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose( - "[%s] Remove Rule request body: %O.", - this._context.connectionId, + managementClientLogger.verbose( + "%s Remove Rule request body: %O.", + this.logPrefix, request.body ); - await this._makeManagementRequest(request, options); + await this._makeManagementRequest(request, managementClientLogger, options); } catch (err) { const error = translate(err); - logError( + managementClientLogger.logError( error, - "An error occurred while sending the remove rule request to $management " + "endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the remove rule request to $management endpoint` ); throw error; } @@ -1327,14 +1292,13 @@ export class ManagementClient extends LinkEntity { }; request.application_properties![Constants.trackingId] = generate_uuid(); - logger.verbose("[%s] Add Rule request body: %O.", this._context.connectionId, request.body); - await this._makeManagementRequest(request, options); + managementClientLogger.verbose("%s Add Rule request body: %O.", this.logPrefix, request.body); + await this._makeManagementRequest(request, managementClientLogger, options); } catch (err) { const error = translate(err); - logError( + managementClientLogger.logError( error, - "An error occurred while sending the Add rule request to $management " + "endpoint: %O", - error + `${this.logPrefix} An error occurred while sending the Add rule request to $management endpoint` ); throw error; } diff --git a/sdk/servicebus/service-bus/src/core/messageReceiver.ts b/sdk/servicebus/service-bus/src/core/messageReceiver.ts index 83c54172faa2..db7311f30409 100644 --- a/sdk/servicebus/service-bus/src/core/messageReceiver.ts +++ b/sdk/servicebus/service-bus/src/core/messageReceiver.ts @@ -9,7 +9,7 @@ import { translate } from "@azure/core-amqp"; import { AmqpError, EventContext, OnAmqpEvent, Receiver, ReceiverOptions } from "rhea-promise"; -import { logger } from "../log"; +import { receiverLogger as logger } from "../log"; import { LinkEntity, ReceiverType } from "./linkEntity"; import { ConnectionContext } from "../connectionContext"; import { DispositionType, InternalReceiveMode, ServiceBusMessageImpl } from "../serviceBusMessage"; @@ -18,7 +18,6 @@ import { SubscribeOptions } from "../models"; import { DispositionStatusOptions } from "./managementClient"; import { AbortSignalLike } from "@azure/core-http"; import { onMessageSettled, DeferredPromiseAndTimer } from "./shared"; -import { logError } from "../util/errors"; import { LockRenewer } from "./autoLockRenewer"; /** @@ -140,7 +139,7 @@ export abstract class MessageReceiver extends LinkEntity { receiverType: ReceiverType, options: Omit ) { - super(entityPath, entityPath, context, receiverType, { + super(entityPath, entityPath, context, receiverType, logger, { address: entityPath, audience: `${context.config.endpoint}${entityPath}` }); @@ -172,11 +171,7 @@ export abstract class MessageReceiver extends LinkEntity { }, credit_window: 0, onSettled: (context) => { - return onMessageSettled( - this._context.connection.id, - context.delivery, - this._deliveryDispositionMap - ); + return onMessageSettled(this.logPrefix, context.delivery, this._deliveryDispositionMap); }, ...handlers }; @@ -198,13 +193,7 @@ export abstract class MessageReceiver extends LinkEntity { this._context.messageReceivers[this.name] = this as any; } catch (err) { err = translate(err); - logError( - err, - "[%s] An error occured while creating the receiver '%s': %O", - this._context.connectionId, - this.name, - err - ); + logger.logError(err, "%s An error occured while creating the receiver", this.logPrefix); // Fix the unhelpful error messages for the OperationTimeoutError that comes from `rhea-promise`. if ((err as MessagingError).code === "OperationTimeoutError") { @@ -263,9 +252,9 @@ export abstract class MessageReceiver extends LinkEntity { this._deliveryDispositionMap.delete(delivery.id); logger.verbose( - "[%s] Disposition for delivery id: %d, did not complete in %d milliseconds. " + + "%s Disposition for delivery id: %d, did not complete in %d milliseconds. " + "Hence rejecting the promise with timeout error.", - this._context.connectionId, + this.logPrefix, delivery.id, Constants.defaultOperationTimeoutInMs ); diff --git a/sdk/servicebus/service-bus/src/core/messageSender.ts b/sdk/servicebus/service-bus/src/core/messageSender.ts index 81afe2f7d973..bbb589d3cc80 100644 --- a/sdk/servicebus/service-bus/src/core/messageSender.ts +++ b/sdk/servicebus/service-bus/src/core/messageSender.ts @@ -1,7 +1,7 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT license. -import { logger } from "../log"; +import { senderLogger as logger } from "../log"; import { AmqpError, AwaitableSender, @@ -31,7 +31,7 @@ import { import { ConnectionContext } from "../connectionContext"; import { LinkEntity } from "./linkEntity"; import { getUniqueName, waitForTimeoutOrAbortOrResolve } from "../util/utils"; -import { logError, throwErrorIfConnectionClosed } from "../util/errors"; +import { throwErrorIfConnectionClosed } from "../util/errors"; import { ServiceBusMessageBatch, ServiceBusMessageBatchImpl } from "../serviceBusMessageBatch"; import { CreateBatchOptions } from "../models"; import { OperationOptionsBase } from "../modelsToBeSharedWithEventHubs"; @@ -69,35 +69,33 @@ export class MessageSender extends LinkEntity { private _retryOptions: RetryOptions; constructor(context: ConnectionContext, entityPath: string, retryOptions: RetryOptions) { - super(entityPath, entityPath, context, "s", { + super(entityPath, entityPath, context, "sender", logger, { address: entityPath, audience: `${context.config.endpoint}${entityPath}` }); this._retryOptions = retryOptions; this._onAmqpError = (context: EventContext) => { const senderError = context.sender && context.sender.error; - logError( + logger.logError( senderError, - "[%s] 'sender_error' event occurred on the sender '%s' with address '%s'. " + - "The associated error is: %O", - this._context.connectionId, + "%s 'sender_error' event occurred on the sender '%s' with address '%s'. " + + "The associated error", + this.logPrefix, this.name, - this.address, - senderError + this.address ); // TODO: Consider rejecting promise in trySendBatch() or createBatch() }; this._onSessionError = (context: EventContext) => { const sessionError = context.session && context.session.error; - logError( + logger.logError( sessionError, - "[%s] 'session_error' event occurred on the session of sender '%s' with address '%s'. " + - "The associated error is: %O", - this._context.connectionId, + "%s 'session_error' event occurred on the session of sender '%s' with address '%s'. " + + "The associated error", + this.logPrefix, this.name, - this.address, - sessionError + this.address ); // TODO: Consider rejecting promise in trySendBatch() or createBatch() }; @@ -105,17 +103,15 @@ export class MessageSender extends LinkEntity { this._onAmqpClose = async (context: EventContext) => { const senderError = context.sender && context.sender.error; - logError( + logger.logError( senderError, - `${this.logPrefix} 'sender_close' event occurred. The associated error is: %O`, - senderError + `${this.logPrefix} 'sender_close' event occurred. The associated error is` ); await this.onDetached().catch((err) => { - logError( + logger.logError( err, - `${this.logPrefix} error when closing sender after 'sender_close' event: %O`, - err + `${this.logPrefix} error when closing sender after 'sender_close' event` ); }); }; @@ -123,17 +119,15 @@ export class MessageSender extends LinkEntity { this._onSessionClose = async (context: EventContext) => { const sessionError = context.session && context.session.error; - logError( + logger.logError( sessionError, - `${this.logPrefix} 'session_close' event occurred. The associated error is: %O`, - sessionError + `${this.logPrefix} 'session_close' event occurred. The associated error is` ); await this.onDetached().catch((err) => { - logError( + logger.logError( err, - `${this.logPrefix} error when closing sender after 'session_close' event: %O`, - err + `${this.logPrefix} error when closing sender after 'session_close' event` ); }); }; @@ -152,7 +146,7 @@ export class MessageSender extends LinkEntity { onSessionClose: this._onSessionClose, sendTimeoutInSeconds: timeoutInMs / 1000 }; - logger.verbose("Creating sender with options: %O", srOptions); + logger.verbose(`${this.logPrefix} Creating sender with options: %O`, srOptions); return srOptions; } @@ -194,12 +188,11 @@ export class MessageSender extends LinkEntity { }); } catch (err) { err = translate(err); - logError( + logger.logError( err, - "[%s] An error occurred while creating the sender %s", - this._context.connectionId, - this.name, - err + "%s An error occurred while creating the sender", + this.logPrefix, + this.name ); return reject(err); } @@ -209,8 +202,8 @@ export class MessageSender extends LinkEntity { const timeTakenByInit = Date.now() - initStartTime; logger.verbose( - "[%s] Sender '%s', credit: %d available: %d", - this._context.connectionId, + "%s Sender '%s', credit: %d available: %d", + this.logPrefix, this.name, this.link?.credit, this.link?.session?.outgoing?.available() @@ -218,16 +211,16 @@ export class MessageSender extends LinkEntity { if (!this.link?.sendable()) { logger.verbose( - "[%s] Sender '%s', waiting for 1 second for sender to become sendable", - this._context.connectionId, + "%s Sender '%s', waiting for 1 second for sender to become sendable", + this.logPrefix, this.name ); await delay(1000); logger.verbose( - "[%s] Sender '%s' after waiting for a second, credit: %d available: %d", - this._context.connectionId, + "%s Sender '%s' after waiting for a second, credit: %d available: %d", + this.logPrefix, this.name, this.link?.credit, this.link?.session?.outgoing?.available() @@ -236,7 +229,7 @@ export class MessageSender extends LinkEntity { if (this.link?.sendable()) { if (timeoutInMs <= timeTakenByInit) { const desc: string = - `[${this._context.connectionId}] Sender "${this.name}" ` + + `${this.logPrefix} Sender "${this.name}" ` + `with address "${this.address}", was not able to send the message right now, due ` + `to operation timeout.`; logger.warning(desc); @@ -254,26 +247,24 @@ export class MessageSender extends LinkEntity { sendBatch ? 0x80013700 : 0 ); logger.verbose( - "[%s] Sender '%s', sent message with delivery id: %d", - this._context.connectionId, + "%s Sender '%s', sent message with delivery id: %d", + this.logPrefix, this.name, delivery.id ); return resolve(); } catch (error) { error = translate(error.innerError || error); - logError( + logger.logError( error, - "[%s] An error occurred while sending the message", - this._context.connectionId, - error + `${this.logPrefix} An error occurred while sending the message` ); return reject(error); } } else { // let us retry to send the message after some time. const msg = - `[${this._context.connectionId}] Sender "${this.name}", ` + + `[${this.logPrefix}] Sender "${this.name}", ` + `cannot send the message right now. Please try later.`; logger.warning(msg); const amqpError: AmqpError = { @@ -318,13 +309,7 @@ export class MessageSender extends LinkEntity { await this.initLink(options, abortSignal); } catch (err) { err = translate(err); - logError( - err, - "[%s] An error occurred while creating the sender %s", - this._context.connectionId, - this.name, - err - ); + logger.logError(err, `${this.logPrefix} An error occurred while creating the sender`); // Fix the unhelpful error messages for the OperationTimeoutError that comes from `rhea-promise`. if ((err as MessagingError).code === "OperationTimeoutError") { err.message = "Failed to create a sender within allocated time and retry attempts."; @@ -351,8 +336,8 @@ export class MessageSender extends LinkEntity { isOpen(): boolean { const result: boolean = this.link == null ? false : this.link.isOpen(); logger.verbose( - "[%s] Sender '%s' with address '%s' is open? -> %s", - this._context.connectionId, + "%s Sender '%s' with address '%s' is open? -> %s", + this.logPrefix, this.name, this.address, result @@ -386,21 +371,14 @@ export class MessageSender extends LinkEntity { } throw error; } - logger.verbose( - "[%s] Sender '%s', trying to send message: %O", - this._context.connectionId, - this.name, - data - ); + logger.verbose("%s Sender '%s', trying to send message: %O", this.logPrefix, this.name, data); return await this._trySend(encodedMessage, false, options); } catch (err) { - logError( + logger.logError( err, - "[%s] Sender '%s': An error occurred while sending the message: %O\nError: %O", - this._context.connectionId, - this.name, - data, - err + "%s An error occurred while sending the message: %O\nError", + this.logPrefix, + data ); throw err; } @@ -425,8 +403,8 @@ export class MessageSender extends LinkEntity { inputMessages = [inputMessages]; } logger.verbose( - "[%s] Sender '%s', trying to send Message[]: %O", - this._context.connectionId, + "%s Sender '%s', trying to send Message[]: %O", + this.logPrefix, this.name, inputMessages ); @@ -469,20 +447,19 @@ export class MessageSender extends LinkEntity { const encodedBatchMessage = RheaMessageUtil.encode(batchMessage); logger.verbose( - "[%s]Sender '%s', sending encoded batch message.", - this._context.connectionId, + "%s Sender '%s', sending encoded batch message.", + this.logPrefix, this.name, encodedBatchMessage ); return await this._trySend(encodedBatchMessage, true, options); } catch (err) { - logError( + logger.logError( err, - "[%s] Sender '%s': An error occurred while sending the messages: %O\nError: %O", - this._context.connectionId, + "%s Sender '%s': An error occurred while sending the messages: %O\nError", + this.logPrefix, this.name, - inputMessages, - err + inputMessages ); throw err; } @@ -556,20 +533,19 @@ export class MessageSender extends LinkEntity { throwErrorIfConnectionClosed(this._context); try { logger.verbose( - "[%s]Sender '%s', sending encoded batch message.", - this._context.connectionId, + "%s Sender '%s', sending encoded batch message.", + this.logPrefix, this.name, batchMessage ); return await this._trySend(batchMessage._generateMessage(), true, options); } catch (err) { - logError( + logger.logError( err, - "[%s] Sender '%s': An error occurred while sending the messages: %O\nError: %O", - this._context.connectionId, + "%s Sender '%s': An error occurred while sending the messages: %O\nError", + this.logPrefix, this.name, - batchMessage, - err + batchMessage ); throw err; } diff --git a/sdk/servicebus/service-bus/src/core/receiverHelper.ts b/sdk/servicebus/service-bus/src/core/receiverHelper.ts index ab7033cac4b3..d49850ba59dc 100644 --- a/sdk/servicebus/service-bus/src/core/receiverHelper.ts +++ b/sdk/servicebus/service-bus/src/core/receiverHelper.ts @@ -2,7 +2,7 @@ // Licensed under the MIT license. import { Receiver, ReceiverEvents } from "rhea-promise"; -import { logger } from "../log"; +import { receiverLogger as logger } from "../log"; /** * Wraps the receiver with some higher level operations for managing state @@ -14,7 +14,9 @@ import { logger } from "../log"; export class ReceiverHelper { private _isSuspended: boolean = false; - constructor(private _getCurrentReceiver: () => Receiver | undefined) {} + constructor( + private _getCurrentReceiver: () => { receiver: Receiver | undefined; logPrefix: string } + ) {} /** * Adds credits to the receiver, respecting any state that @@ -26,13 +28,17 @@ export class ReceiverHelper { * or `stopReceivingMessages` has been called. */ addCredit(credits: number): boolean { - const receiver = this._getCurrentReceiver(); + const { receiver, logPrefix } = this._getCurrentReceiver(); if (!this.canReceiveMessages()) { + logger.verbose( + `${logPrefix} Asked to add ${credits} credits but the receiver is not able to receive messages` + ); return false; } if (receiver != null) { + logger.verbose(`${logPrefix} Adding ${credits} credits`); receiver.addCredit(credits); } @@ -44,7 +50,7 @@ export class ReceiverHelper { * Call `resume()` to enable the `addCredit()` method. */ async suspend(): Promise { - const receiver = this._getCurrentReceiver(); + const { receiver, logPrefix } = this._getCurrentReceiver(); this._isSuspended = true; @@ -53,7 +59,7 @@ export class ReceiverHelper { } logger.verbose( - `[${receiver.name}] User has requested to stop receiving new messages, attempting to drain the credits.` + `${logPrefix} User has requested to stop receiving new messages, attempting to drain.` ); return this.drain(); } @@ -73,7 +79,7 @@ export class ReceiverHelper { * still open. */ canReceiveMessages(): boolean { - const receiver = this._getCurrentReceiver(); + const { receiver } = this._getCurrentReceiver(); return !this._isSuspended && this._isValidReceiver(receiver); } @@ -82,17 +88,19 @@ export class ReceiverHelper { * the drain has completed. */ async drain(): Promise { - const receiver = this._getCurrentReceiver(); + const { receiver, logPrefix } = this._getCurrentReceiver(); if (!this._isValidReceiver(receiver)) { return; } - logger.verbose(`[${receiver.name}] Receiver is starting drain.`); + logger.verbose( + `${logPrefix} Receiver is starting drain. Remaining credits; ${receiver.credit}` + ); const drainPromise = new Promise((resolve) => { receiver.once(ReceiverEvents.receiverDrained, () => { - logger.verbose(`[${receiver.name}] Receiver has been drained.`); + logger.verbose(`${logPrefix} Receiver has been drained.`); receiver.drain = false; resolve(); }); diff --git a/sdk/servicebus/service-bus/src/core/shared.ts b/sdk/servicebus/service-bus/src/core/shared.ts index 6d23aac278e1..41c306c0c48b 100644 --- a/sdk/servicebus/service-bus/src/core/shared.ts +++ b/sdk/servicebus/service-bus/src/core/shared.ts @@ -3,7 +3,7 @@ import { Delivery } from "rhea-promise"; import { translate } from "@azure/core-amqp"; -import { logger } from "../log"; +import { receiverLogger } from "../log"; /** * @internal @@ -29,7 +29,7 @@ export interface DeferredPromiseAndTimer { * @ignore */ export function onMessageSettled( - connectionId: string, + logPrefix: string, delivery: Delivery | undefined, deliveryDispositionMap: Map ): void { @@ -37,9 +37,9 @@ export function onMessageSettled( const id = delivery.id; const state = delivery.remote_state; const settled = delivery.remote_settled; - logger.verbose( - "[%s] Delivery with id %d, remote_settled: %s, remote_state: %o has been " + "received.", - connectionId, + receiverLogger.verbose( + "%s Delivery with id %d, remote_settled: %s, remote_state: %o has been " + "received.", + logPrefix, id, settled, state && state.error ? state.error : state @@ -47,15 +47,15 @@ export function onMessageSettled( if (settled && deliveryDispositionMap.has(id)) { const promise = deliveryDispositionMap.get(id) as DeferredPromiseAndTimer; clearTimeout(promise.timer); - logger.verbose( - "[%s] Found the delivery with id %d in the map and cleared the timer.", - connectionId, + receiverLogger.verbose( + "%s Found the delivery with id %d in the map and cleared the timer.", + logPrefix, id ); const deleteResult = deliveryDispositionMap.delete(id); - logger.verbose( - "[%s] Successfully deleted the delivery with id %d from the map.", - connectionId, + receiverLogger.verbose( + "%s Successfully deleted the delivery with id %d from the map.", + logPrefix, id, deleteResult ); diff --git a/sdk/servicebus/service-bus/src/core/streamingReceiver.ts b/sdk/servicebus/service-bus/src/core/streamingReceiver.ts index 5f0d35c214f9..0403fa613d9b 100644 --- a/sdk/servicebus/service-bus/src/core/streamingReceiver.ts +++ b/sdk/servicebus/service-bus/src/core/streamingReceiver.ts @@ -13,7 +13,7 @@ import { ConnectionContext } from "../connectionContext"; import { ReceiverHelper } from "./receiverHelper"; -import { logError, throwErrorIfConnectionClosed } from "../util/errors"; +import { throwErrorIfConnectionClosed } from "../util/errors"; import { RetryOperationType, RetryConfig, @@ -24,7 +24,7 @@ import { ConditionErrorNameMapper } from "@azure/core-amqp"; import { OperationOptionsBase } from "../modelsToBeSharedWithEventHubs"; -import { logger } from "../log"; +import { receiverLogger as logger } from "../log"; import { AmqpError, EventContext, isAmqpError, OnAmqpEvent } from "rhea-promise"; import { InternalReceiveMode, ServiceBusMessageImpl } from "../serviceBusMessage"; import { AbortSignalLike } from "@azure/abort-controller"; @@ -124,24 +124,25 @@ export class StreamingReceiver extends MessageReceiver { * @param {ReceiveOptions} [options] Options for how you'd like to connect. */ constructor(context: ConnectionContext, entityPath: string, options: ReceiveOptions) { - super(context, entityPath, "sr", options); + super(context, entityPath, "streaming", options); if (typeof options?.maxConcurrentCalls === "number" && options?.maxConcurrentCalls > 0) { this.maxConcurrentCalls = options.maxConcurrentCalls; } this._retryOptions = options?.retryOptions || {}; - this._receiverHelper = new ReceiverHelper(() => this.link); + this._receiverHelper = new ReceiverHelper(() => ({ + receiver: this.link, + logPrefix: this.logPrefix + })); this._onAmqpClose = async (context: EventContext) => { - const connectionId = this._context.connectionId; const receiverError = context.receiver && context.receiver.error; const receiver = this.link || context.receiver!; - logError( + logger.logError( receiverError, - `${this.logPrefix} 'receiver_close' event occurred. The associated error is: %O`, - receiverError + `${this.logPrefix} 'receiver_close' event occurred. The associated error is` ); this._lockRenewer?.stopAll(this); @@ -150,10 +151,10 @@ export class StreamingReceiver extends MessageReceiver { await this.onDetached(receiverError); } else { logger.verbose( - "[%s] 'receiver_close' event occurred on the receiver '%s' with address '%s' " + + "%s 'receiver_close' event occurred on the receiver '%s' with address '%s' " + "because the sdk initiated it. Hence not calling detached from the _onAmqpClose" + "() handler.", - connectionId, + this.logPrefix, this.name, this.address ); @@ -161,14 +162,12 @@ export class StreamingReceiver extends MessageReceiver { }; this._onSessionClose = async (context: EventContext) => { - const connectionId = this._context.connectionId; const receiver = this.link || context.receiver!; const sessionError = context.session && context.session.error; - logError( + logger.logError( sessionError, - `${this.logPrefix} 'session_close' event occurred. The associated error is: %O`, - sessionError + `${this.logPrefix} 'session_close' event occurred. The associated error is` ); this._lockRenewer?.stopAll(this); @@ -177,10 +176,10 @@ export class StreamingReceiver extends MessageReceiver { await this.onDetached(sessionError); } else { logger.verbose( - "[%s] 'session_close' event occurred on the session of receiver '%s' with address " + + "%s 'session_close' event occurred on the session of receiver '%s' with address " + "'%s' because the sdk initiated it. Hence not calling detached from the _onSessionClose" + "() handler.", - connectionId, + this.logPrefix, this.name, this.address ); @@ -188,61 +187,52 @@ export class StreamingReceiver extends MessageReceiver { }; this._onAmqpError = (context: EventContext) => { - const connectionId = this._context.connectionId; const receiver = this.link || context.receiver!; const receiverError = context.receiver && context.receiver.error; if (receiverError) { const sbError = translate(receiverError) as MessagingError; - logError( - sbError, - "[%s] An error occurred for Receiver '%s': %O.", - connectionId, - this.name, - sbError - ); + logger.logError(sbError, `${this.logPrefix} An error occurred for Receiver`); if (!sbError.retryable) { if (receiver && !receiver.isItselfClosed()) { logger.verbose( - "[%s] Since the user did not close the receiver and the error is not " + + "%s Since the user did not close the receiver and the error is not " + "retryable, we let the user know about it by calling the user's error handler.", - connectionId + this.logPrefix ); this._onError!(sbError); } else { logger.verbose( - "[%s] The received error is not retryable. However, the receiver was " + + "%s The received error is not retryable. However, the receiver was " + "closed by the user. Hence not notifying the user's error handler.", - connectionId + this.logPrefix ); } } else { logger.verbose( - "[%s] Since received error is retryable, we will NOT notify the user's " + + "%s Since received error is retryable, we will NOT notify the user's " + "error handler.", - connectionId + this.logPrefix ); } } }; this._onSessionError = (context: EventContext) => { - const connectionId = this._context.connectionId; const receiver = this.link || context.receiver!; const sessionError = context.session && context.session.error; if (sessionError) { const sbError = translate(sessionError) as MessagingError; - logError( + logger.logError( sbError, - "[%s] An error occurred on the session for Receiver '%s': %O.", - connectionId, - this.name, - sbError + "%s An error occurred on the session for Receiver '%s'", + this.logPrefix, + this.name ); if (receiver && !receiver.isSessionItselfClosed() && !sbError.retryable) { logger.verbose( - "[%s] Since the user did not close the receiver and the session error is not " + + "%s Since the user did not close the receiver and the session error is not " + "retryable, we let the user know about it by calling the user's error handler.", - connectionId + this.logPrefix ); this._onError!(sbError); } @@ -257,15 +247,13 @@ export class StreamingReceiver extends MessageReceiver { (!this.link || !this.link.isOpen()) ) { logger.verbose( - "[%s] Not calling the user's message handler for the current message " + - "as the receiver '%s' is closed", - this._context.connectionId, - this.name + "%s Not calling the user's message handler for the current message " + + "as the receiver is closed", + this.logPrefix ); return; } - const connectionId = this._context.connectionId; const bMessage: ServiceBusMessageImpl = new ServiceBusMessageImpl( this._context, this.entityPath, @@ -286,14 +274,13 @@ export class StreamingReceiver extends MessageReceiver { } catch (err) { // This ensures we call users' error handler when users' message handler throws. if (!isAmqpError(err)) { - logError( + logger.logError( err, - "[%s] An error occurred while running user's message handler for the message " + - "with id '%s' on the receiver '%s': %O", - connectionId, + "%s An error occurred while running user's message handler for the message " + + "with id '%s' on the receiver '%s'", + this.logPrefix, bMessage.messageId, - this.name, - err + this.name ); this._onError!(err); } @@ -310,11 +297,11 @@ export class StreamingReceiver extends MessageReceiver { this.isOpen() // only try to abandon the messages if the connection is still open ) { try { - logError( + logger.logError( error, - "[%s] Abandoning the message with id '%s' on the receiver '%s' since " + + "%s Abandoning the message with id '%s' on the receiver '%s' since " + "an error occured: %O.", - connectionId, + this.logPrefix, bMessage.messageId, this.name, error @@ -322,14 +309,13 @@ export class StreamingReceiver extends MessageReceiver { await bMessage.abandon(); } catch (abandonError) { const translatedError = translate(abandonError); - logError( + logger.logError( translatedError, - "[%s] An error occurred while abandoning the message with id '%s' on the " + - "receiver '%s': %O.", - connectionId, + "%s An error occurred while abandoning the message with id '%s' on the " + + "receiver '%s'", + this.logPrefix, bMessage.messageId, - this.name, - translatedError + this.name ); this._onError!(translatedError); } @@ -348,22 +334,20 @@ export class StreamingReceiver extends MessageReceiver { ) { try { logger.verbose( - "[%s] Auto completing the message with id '%s' on " + "the receiver '%s'.", - connectionId, - bMessage.messageId, - this.name + "%s Auto completing the message with id '%s' on " + "the receiver.", + this.logPrefix, + bMessage.messageId ); await bMessage.complete(); } catch (completeError) { const translatedError = translate(completeError); - logError( + logger.logError( translatedError, - "[%s] An error occurred while completing the message with id '%s' on the " + - "receiver '%s': %O.", - connectionId, + "%s An error occurred while completing the message with id '%s' on the " + + "receiver '%s'", + this.logPrefix, bMessage.messageId, - this.name, - translatedError + this.name ); this._onError!(translatedError); } @@ -446,7 +430,7 @@ export class StreamingReceiver extends MessageReceiver { // These should be ignored until the already running `onDetached` completes // its retry attempts or errors. logger.verbose( - `[${connectionId}] Call to detached on streaming receiver '${this.name}' is already in progress.` + `${this.logPrefix} Call to detached on streaming receiver '${this.name}' is already in progress.` ); return; } @@ -477,13 +461,12 @@ export class StreamingReceiver extends MessageReceiver { // will have already been forwarded to the user's error handler. // Swallow the error and return quickly. if (!shouldReopen && !causedByDisconnect) { - logError( + logger.logError( translatedError, - "[%s] Encountered a non retryable error on the receiver. Cannot recover receiver '%s' with address '%s' encountered error: %O", - connectionId, + "%s Encountered a non retryable error on the receiver. Cannot recover receiver. encountered error", + this.logPrefix, this.name, - this.address, - translatedError + this.address ); return; } @@ -492,13 +475,12 @@ export class StreamingReceiver extends MessageReceiver { // haven't had a chance to show up in the user's error handler. // Rethrow the error so the surrounding try/catch forwards it appropriately. if (!shouldReopen && causedByDisconnect) { - logError( + logger.logError( translatedError, - "[%s] Encountered a non retryable error on the connection. Cannot recover receiver '%s' with address '%s': %O", - connectionId, + "%s Encountered a non retryable error on the connection. Cannot recover receiver.", + this.logPrefix, this.name, - this.address, - translatedError + this.address ); throw translatedError; } @@ -524,29 +506,21 @@ export class StreamingReceiver extends MessageReceiver { // retry will throw and the error will surface to the user's error handler. await retry(config); } catch (err) { - logError( + logger.logError( err, - "[%s] An error occurred while processing detached() of Receiver '%s': %O ", - connectionId, + "%s An error occurred while processing detached()", + this.logPrefix, this.name, - this.address, - err + this.address ); if (typeof this._onError === "function") { - logger.verbose( - "[%s] Unable to automatically reconnect Receiver '%s' with address '%s'.", - connectionId, - this.name, - this.address - ); + logger.verbose(`${this.logPrefix} Unable to automatically reconnect`); try { this._onError(err); } catch (err) { - logError( + logger.logError( err, - "[%s] User-code error in error handler called after disconnect: %O", - connectionId, - err + `${this.logPrefix} User-code error in error handler called after disconnect` ); } finally { // Once the user's error handler has been called, diff --git a/sdk/servicebus/service-bus/src/log.ts b/sdk/servicebus/service-bus/src/log.ts index 5eb5c4ad6659..74641c578aa2 100644 --- a/sdk/servicebus/service-bus/src/log.ts +++ b/sdk/servicebus/service-bus/src/log.ts @@ -1,23 +1,128 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT license. -import { createClientLogger } from "@azure/logger"; +import { AzureLogger, createClientLogger } from "@azure/logger"; +import { AmqpError } from "rhea-promise"; /** * The @azure/logger configuration for this package. - * This will output logs using the `azure:event-hubs` namespace prefix. + * This will output logs using the `azure:service-bus` namespace prefix. + * @internal + * @ignore + */ +export const logger = createServiceBusLogger("service-bus"); + +/** + * Logging for ServiceBusReceivers of any type (session, non-session) + * @internal + * @ignore + */ +export const receiverLogger = createServiceBusLogger("service-bus:receiver"); + +/** + * Logging for ServiceBusSenders + * @internal + * @ignore + */ +export const senderLogger = createServiceBusLogger("service-bus:sender"); + +/** + * Logging for connection management + * @internal + * @ignore + */ +export const connectionLogger = createServiceBusLogger("service-bus:connection"); + +/** + * Logging for the ServiceBusAdministrationClient + * @internal * @ignore + */ +export const administrationLogger = createServiceBusLogger("service-bus:administration"); + +/** + * Logging related to message encoding/decoding. * @internal + * @ignore */ -export const logger = createClientLogger("service-bus"); +export const messageLogger = createServiceBusLogger("service-bus:messages"); + +/** + * Logging related to message encoding/decoding. + * @internal + * @ignore + */ +export const managementClientLogger = createServiceBusLogger("service-bus:management"); /** * Logs the error's stack trace to "verbose" if a stack trace is available. * @param error Error containing a stack trace. + * @internal * @ignore */ -export function logErrorStackTrace(error: any) { +export function logErrorStackTrace(_logger: AzureLogger, error: any) { if (error && error.stack) { - logger.verbose(error.stack); + _logger.verbose(error.stack); } } + +/** + * @internal + * @ignore + */ +export interface ServiceBusLogger extends AzureLogger { + /** + * Logs an error with an associated message, formatted. If there is a stack + * trace in the error that will be logged to the verbose stream. + * + * Example: + * receiverLogger.logError(new Error("hello, this is the error"), "this is my message"); + * will output: + * azure:service-bus:receiver:warning this is my message : Error: hello, this is the error + * @param err + * @param args + */ + logError(err: Error | AmqpError | undefined, ...args: any[]): void; +} + +/** + * Creates an AzureLogger with any additional methods for standardized logging (for example, with errors) + * @internal + * @ignore + */ +export function createServiceBusLogger(namespace: string) { + const _logger = createClientLogger(namespace) as ServiceBusLogger; + + _logger["logError"] = (err: Error | AmqpError | undefined, ...args: any[]): void => { + let l: typeof logger.info; + + // abort errors are user initiated so we don't have to treat them as warnings, like we + // would with other errors. + if (isError(err) && err.name === "AbortError") { + l = _logger.info; + } else { + l = _logger.warning; + } + + // tack on the error object so it also gets logged. + args.push(":", err); + + // let the normal formatting work and include the error at the end. + l(...args); + + // optionally log the stack trace if it's available but this always goes to verbose + if (err && (err as any).stack) { + _logger.verbose((err as any).stack); + } + }; + + return _logger; +} + +/** + * @internal + * @ignore + */ +function isError(err: Error | AmqpError | undefined): err is Error { + return err != null && (err as any).name != null; +} diff --git a/sdk/servicebus/service-bus/src/receivers/receiver.ts b/sdk/servicebus/service-bus/src/receivers/receiver.ts index 7b6ae2d13880..a3a4e1400638 100644 --- a/sdk/servicebus/service-bus/src/receivers/receiver.ts +++ b/sdk/servicebus/service-bus/src/receivers/receiver.ts @@ -15,7 +15,6 @@ import { ConnectionContext } from "../connectionContext"; import { getAlreadyReceivingErrorMsg, getReceiverClosedErrorMsg, - logError, throwErrorIfConnectionClosed, throwTypeErrorIfParameterMissing, throwTypeErrorIfParameterNotLong @@ -30,6 +29,7 @@ import { ServiceBusReceivedMessageWithLock, ServiceBusMessageImpl } from "../ser import { Constants, RetryConfig, RetryOperationType, RetryOptions, retry } from "@azure/core-amqp"; import "@azure/core-asynciterator-polyfill"; import { LockRenewer } from "../core/autoLockRenewer"; +import { receiverLogger as logger } from "../log"; /** * A receiver that does not handle sessions. @@ -158,6 +158,10 @@ export class ServiceBusReceiverImpl< private _streamingReceiver?: StreamingReceiver; private _lockRenewer: LockRenewer | undefined; + private get logPrefix() { + return `[${this._context.connectionId}|receiver:${this.entityPath}]`; + } + /** * @throws Error if the underlying connection is closed. */ @@ -181,7 +185,7 @@ export class ServiceBusReceiverImpl< if (this._isReceivingMessages()) { const errorMessage = getAlreadyReceivingErrorMsg(this.entityPath); const error = new Error(errorMessage); - logError(error, `[${this._context.connectionId}] %O`, error); + logger.logError(error, `${this.logPrefix} is already receiving`); throw error; } } @@ -191,7 +195,7 @@ export class ServiceBusReceiverImpl< if (this.isClosed) { const errorMessage = getReceiverClosedErrorMsg(this.entityPath); const error = new Error(errorMessage); - logError(error, `[${this._context.connectionId}] %O`, error); + logger.logError(error, `${this.logPrefix} is closed`); throw error; } } @@ -464,13 +468,7 @@ export class ServiceBusReceiverImpl< } } } catch (err) { - logError( - err, - "[%s] An error occurred while closing the Receiver for %s: %O", - this._context.connectionId, - this.entityPath, - err - ); + logger.logError(err, `${this.logPrefix} An error occurred while closing the Receiver`); throw err; } } diff --git a/sdk/servicebus/service-bus/src/receivers/sessionReceiver.ts b/sdk/servicebus/service-bus/src/receivers/sessionReceiver.ts index 9846af398af6..b14f26bbb995 100644 --- a/sdk/servicebus/service-bus/src/receivers/sessionReceiver.ts +++ b/sdk/servicebus/service-bus/src/receivers/sessionReceiver.ts @@ -8,7 +8,6 @@ import { MessageSession } from "../session/messageSession"; import { getAlreadyReceivingErrorMsg, getReceiverClosedErrorMsg, - logError, throwErrorIfConnectionClosed, throwTypeErrorIfParameterMissing, throwTypeErrorIfParameterNotLong @@ -31,6 +30,7 @@ import { import { OperationOptionsBase } from "../modelsToBeSharedWithEventHubs"; import "@azure/core-asynciterator-polyfill"; import { AmqpError } from "rhea-promise"; +import { receiverLogger as logger } from "../log"; /** *A receiver that handles sessions, including renewing the session lock. @@ -114,6 +114,10 @@ export class ServiceBusSessionReceiverImpl< */ private _isClosed: boolean = false; + private get logPrefix() { + return `[${this._context.connectionId}|session:${this.entityPath}]`; + } + /** * @internal * @throws Error if the underlying connection is closed. @@ -136,7 +140,7 @@ export class ServiceBusSessionReceiverImpl< if (this._isClosed) { const errorMessage = getReceiverClosedErrorMsg(this.entityPath, this.sessionId); const error = new Error(errorMessage); - logError(error, `[${this._context.connectionId}] %O`, error); + logger.logError(error, `${this.logPrefix} already closed`); throw error; } const amqpError: AmqpError = { @@ -151,7 +155,7 @@ export class ServiceBusSessionReceiverImpl< if (this._isReceivingMessages()) { const errorMessage = getAlreadyReceivingErrorMsg(this.entityPath, this.sessionId); const error = new Error(errorMessage); - logError(error, `[${this._context.connectionId}] %O`, error); + logger.logError(error, `${this.logPrefix} is already receiving.`); throw error; } } @@ -479,13 +483,11 @@ export class ServiceBusSessionReceiverImpl< try { await this._messageSession.close(); } catch (err) { - logError( + logger.logError( err, - "[%s] An error occurred while closing the SessionReceiver for session %s in %s: %O", - this._context.connectionId, - this.sessionId, - this.entityPath, - err + "%s An error occurred while closing the SessionReceiver for session %s", + this.logPrefix, + this.sessionId ); throw err; } finally { diff --git a/sdk/servicebus/service-bus/src/receivers/shared.ts b/sdk/servicebus/service-bus/src/receivers/shared.ts index bff3b8535953..7d1f54dcc1b1 100644 --- a/sdk/servicebus/service-bus/src/receivers/shared.ts +++ b/sdk/servicebus/service-bus/src/receivers/shared.ts @@ -4,7 +4,7 @@ import { MessageHandlers } from "../models"; import { ServiceBusReceiver } from "./receiver"; import { OperationOptionsBase } from "../modelsToBeSharedWithEventHubs"; -import { logger } from "../log"; +import { receiverLogger, ServiceBusLogger } from "../log"; /** * @internal @@ -47,13 +47,13 @@ export async function* getMessageIterator( */ export function wrapProcessErrorHandler( handlers: Pick, "processError">, - logError: (formatter: any, ...args: any[]) => void = logger.error + logger: ServiceBusLogger = receiverLogger ): MessageHandlers["processError"] { return async (err: Error) => { try { await handlers.processError(err); } catch (err) { - logError(`An error was thrown from the user's processError handler: ${err}`); + logger.logError(err, `An error was thrown from the user's processError handler`); } }; } diff --git a/sdk/servicebus/service-bus/src/sender.ts b/sdk/servicebus/service-bus/src/sender.ts index 07940254c5fb..ba5870712a1c 100644 --- a/sdk/servicebus/service-bus/src/sender.ts +++ b/sdk/servicebus/service-bus/src/sender.ts @@ -7,7 +7,6 @@ import { ServiceBusMessage, isServiceBusMessage } from "./serviceBusMessage"; import { ConnectionContext } from "./connectionContext"; import { getSenderClosedErrorMsg, - logError, throwErrorIfConnectionClosed, throwTypeErrorIfParameterMissing, throwTypeErrorIfParameterNotLong @@ -27,6 +26,7 @@ import { OperationOptionsBase } from "./modelsToBeSharedWithEventHubs"; import { CanonicalCode, SpanContext } from "@opentelemetry/api"; +import { senderLogger as logger } from "./log"; /** * A Sender can be used to send messages, schedule messages to be sent at a later time @@ -146,6 +146,10 @@ export class ServiceBusSenderImpl implements ServiceBusSender { private _sender: MessageSender; public entityPath: string; + private get logPrefix() { + return `[${this._context.connectionId}|sender:${this.entityPath}]`; + } + /** * @internal * @throws Error if the underlying connection is closed. @@ -166,7 +170,7 @@ export class ServiceBusSenderImpl implements ServiceBusSender { if (this.isClosed) { const errorMessage = getSenderClosedErrorMsg(this._entityPath); const error = new Error(errorMessage); - logError(error, `[${this._context.connectionId}] %O`, error); + logger.logError(error, `[${this._context.connectionId}] is closed`); throw error; } } @@ -342,13 +346,7 @@ export class ServiceBusSenderImpl implements ServiceBusSender { this._isClosed = true; await this._sender.close(); } catch (err) { - logError( - err, - "[%s] An error occurred while closing the Sender for %s: %O", - this._context.connectionId, - this._entityPath, - err - ); + logger.logError(err, `${this.logPrefix} An error occurred while closing the Sender`); throw err; } } diff --git a/sdk/servicebus/service-bus/src/serviceBusAtomManagementClient.ts b/sdk/servicebus/service-bus/src/serviceBusAtomManagementClient.ts index 7550a9e4324a..a75829190562 100644 --- a/sdk/servicebus/service-bus/src/serviceBusAtomManagementClient.ts +++ b/sdk/servicebus/service-bus/src/serviceBusAtomManagementClient.ts @@ -24,7 +24,7 @@ import { } from "@azure/core-http"; import { PagedAsyncIterableIterator, PageSettings } from "@azure/core-paging"; import { CorrelationRuleFilter } from "./core/managementClient"; -import { logger } from "./log"; +import { administrationLogger as logger } from "./log"; import { buildNamespace, NamespaceProperties, @@ -71,7 +71,6 @@ import { } from "./serializers/topicResourceSerializer"; import { AtomXmlSerializer, executeAtomXmlOperation } from "./util/atomXmlHelper"; import * as Constants from "./util/constants"; -import { logError } from "./util/errors"; import { parseURL } from "./util/parseUrl"; import { SasServiceClientCredentials } from "./util/sasServiceClientCredentials"; import { createSpan, getCanonicalCode } from "./util/tracing"; @@ -2463,7 +2462,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { }); return namespaceResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a namespace object using the response from the service.`, RestError.PARSE_ERROR, @@ -2496,7 +2495,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { listQueuesResponse.continuationToken = nextMarker; return listQueuesResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a list of queues using the response from the service.`, RestError.PARSE_ERROR, @@ -2529,7 +2528,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { listQueuesResponse.continuationToken = nextMarker; return listQueuesResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a list of queues using the response from the service.`, RestError.PARSE_ERROR, @@ -2548,7 +2547,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { }); return queueResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a queue object using the response from the service.`, RestError.PARSE_ERROR, @@ -2569,7 +2568,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { }); return queueResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a queue object using the response from the service.`, RestError.PARSE_ERROR, @@ -2602,7 +2601,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { listTopicsResponse.continuationToken = nextMarker; return listTopicsResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a list of topics using the response from the service.`, RestError.PARSE_ERROR, @@ -2635,7 +2634,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { listTopicsResponse.continuationToken = nextMarker; return listTopicsResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a list of topics using the response from the service.`, RestError.PARSE_ERROR, @@ -2653,7 +2652,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { }); return topicResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a topic object using the response from the service.`, RestError.PARSE_ERROR, @@ -2674,7 +2673,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { }); return topicResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a topic object using the response from the service.`, RestError.PARSE_ERROR, @@ -2710,7 +2709,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { listSubscriptionsResponse.continuationToken = nextMarker; return listSubscriptionsResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a list of subscriptions using the response from the service.`, RestError.PARSE_ERROR, @@ -2746,7 +2745,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { listSubscriptionsResponse.continuationToken = nextMarker; return listSubscriptionsResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a list of subscriptions using the response from the service.`, RestError.PARSE_ERROR, @@ -2765,7 +2764,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { }); return subscriptionResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a subscription object using the response from the service.`, RestError.PARSE_ERROR, @@ -2789,7 +2788,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { ); return subscriptionResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a subscription object using the response from the service.`, RestError.PARSE_ERROR, @@ -2822,7 +2821,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { listRulesResponse.continuationToken = nextMarker; return listRulesResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a list of rules using the response from the service.`, RestError.PARSE_ERROR, @@ -2839,7 +2838,7 @@ export class ServiceBusAdministrationClient extends ServiceClient { const ruleResponse: RuleResponse = Object.assign(rule || {}, { _response: response }); return ruleResponse; } catch (err) { - logError(err, "Failure parsing response from service - %0 ", err); + logger.logError(err, "Failure parsing response from service"); throw new RestError( `Error occurred while parsing the response body - cannot form a rule object using the response from the service.`, RestError.PARSE_ERROR, diff --git a/sdk/servicebus/service-bus/src/serviceBusMessage.ts b/sdk/servicebus/service-bus/src/serviceBusMessage.ts index 153f6666ac3a..4ba994fdcf9a 100644 --- a/sdk/servicebus/service-bus/src/serviceBusMessage.ts +++ b/sdk/servicebus/service-bus/src/serviceBusMessage.ts @@ -11,10 +11,10 @@ import { MessageProperties, translate } from "@azure/core-amqp"; -import { logger } from "./log"; +import { messageLogger as logger, receiverLogger } from "./log"; import { ConnectionContext } from "./connectionContext"; import { reorderLockToken } from "./util/utils"; -import { getErrorMessageNotSupportedInReceiveAndDeleteMode, logError } from "./util/errors"; +import { getErrorMessageNotSupportedInReceiveAndDeleteMode } from "./util/errors"; import { Buffer } from "buffer"; import { DispositionStatusOptions } from "./core/managementClient"; @@ -1077,7 +1077,7 @@ export class ServiceBusMessageImpl implements ServiceBusReceivedMessageWithLock * See ServiceBusReceivedMessageWithLock.complete(). */ async complete(): Promise { - logger.verbose( + receiverLogger.verbose( "[%s] Completing the message with id '%s'.", this._context.connectionId, this.messageId @@ -1090,7 +1090,7 @@ export class ServiceBusMessageImpl implements ServiceBusReceivedMessageWithLock */ async abandon(propertiesToModify?: { [key: string]: any }): Promise { // TODO: Figure out a mechanism to convert specified properties to message_annotations. - logger.verbose( + receiverLogger.verbose( "[%s] Abandoning the message with id '%s'.", this._context.connectionId, this.messageId @@ -1104,7 +1104,7 @@ export class ServiceBusMessageImpl implements ServiceBusReceivedMessageWithLock * See ServiceBusReceivedMessageWithLock.defer(). */ async defer(propertiesToModify?: { [key: string]: any }): Promise { - logger.verbose( + receiverLogger.verbose( "[%s] Deferring the message with id '%s'.", this._context.connectionId, this.messageId @@ -1118,7 +1118,7 @@ export class ServiceBusMessageImpl implements ServiceBusReceivedMessageWithLock * See ServiceBusReceivedMessageWithLock.deadLetter(). */ async deadLetter(propertiesToModify?: DeadLetterOptions & { [key: string]: any }): Promise { - logger.verbose( + receiverLogger.verbose( "[%s] Deadlettering the message with id '%s'.", this._context.connectionId, this.messageId @@ -1168,12 +1168,11 @@ export class ServiceBusMessageImpl implements ServiceBusReceivedMessageWithLock error = new Error(`Failed to renew the lock as this message is already settled.`); } if (error) { - logError( + logger.logError( error, - "[%s] An error occurred when renewing the lock on the message with id '%s': %O", + "[%s] An error occurred when renewing the lock on the message with id '%s'", this._context.connectionId, - this.messageId, - error + this.messageId ); throw error; } @@ -1233,12 +1232,11 @@ export class ServiceBusMessageImpl implements ServiceBusReceivedMessageWithLock const error = new Error( getErrorMessageNotSupportedInReceiveAndDeleteMode(`${operation} the message`) ); - logError( + logger.logError( error, - "[%s] An error occurred when settling a message with id '%s': %O", + "[%s] An error occurred when settling a message with id '%s'", this._context.connectionId, - this.messageId, - error + this.messageId ); throw error; } @@ -1268,12 +1266,11 @@ export class ServiceBusMessageImpl implements ServiceBusReceivedMessageWithLock }); } if (error) { - logError( + logger.logError( error, - "[%s] An error occurred when settling a message with id '%s': %O", + "[%s] An error occurred when settling a message with id '%s'", this._context.connectionId, - this.messageId, - error + this.messageId ); throw error; } diff --git a/sdk/servicebus/service-bus/src/session/messageSession.ts b/sdk/servicebus/service-bus/src/session/messageSession.ts index 18bd57ea6f04..1ae0648825b2 100644 --- a/sdk/servicebus/service-bus/src/session/messageSession.ts +++ b/sdk/servicebus/service-bus/src/session/messageSession.ts @@ -15,9 +15,9 @@ import { ConnectionContext } from "../connectionContext"; import { LinkEntity } from "../core/linkEntity"; import { DispositionStatusOptions } from "../core/managementClient"; import { OnAmqpEventAsPromise, OnError, OnMessage } from "../core/messageReceiver"; -import { logger } from "../log"; +import { receiverLogger as logger } from "../log"; import { DispositionType, InternalReceiveMode, ServiceBusMessageImpl } from "../serviceBusMessage"; -import { logError, throwErrorIfConnectionClosed } from "../util/errors"; +import { throwErrorIfConnectionClosed } from "../util/errors"; import { calculateRenewAfterDuration, convertTicksToDate, @@ -188,14 +188,12 @@ export class MessageSession extends LinkEntity { Date.now() < this._totalAutoLockRenewDuration && this.isOpen() ) { - const connectionId = this._context.connectionId; const nextRenewalTimeout = calculateRenewAfterDuration(this.sessionLockedUntilUtc!); this._sessionLockRenewalTimer = setTimeout(async () => { try { logger.verbose( - "[%s] Attempting to renew the session lock for MessageSession '%s' " + - "with name '%s'.", - connectionId, + "%s Attempting to renew the session lock for MessageSession '%s' " + "with name '%s'.", + this.logPrefix, this.sessionId, this.name ); @@ -206,36 +204,30 @@ export class MessageSession extends LinkEntity { timeoutInMs: 10000 }); logger.verbose( - "[%s] Successfully renewed the session lock for MessageSession '%s' " + - "with name '%s'.", - connectionId, + "%s Successfully renewed the session lock for MessageSession '%s' " + "with name '%s'.", + this.logPrefix, this.sessionId, this.name ); logger.verbose( - "[%s] Calling _ensureSessionLockRenewal() again for MessageSession '%s'.", - connectionId, + "%s Calling _ensureSessionLockRenewal() again for MessageSession '%s'.", + this.logPrefix, this.sessionId ); this._ensureSessionLockRenewal(); } catch (err) { - logError( + logger.logError( err, - "[%s] An error occurred while renewing the session lock for MessageSession " + - "'%s' with name '%s': %O", - this._context.connectionId, - this.sessionId, - this.name, - err + "%s An error occurred while renewing the session lock for MessageSession '%s'", + this.logPrefix, + this.sessionId ); } }, nextRenewalTimeout); logger.verbose( - "[%s] MessageSession '%s' with name '%s', has next session lock renewal " + - "in %d milliseconds @(%s).", - this._context.connectionId, + "%s MessageSession '%s' has next session lock renewal in %d milliseconds @(%s).", + this.logPrefix, this.sessionId, - this.name, nextRenewalTimeout, new Date(Date.now() + nextRenewalTimeout).toString() ); @@ -253,7 +245,6 @@ export class MessageSession extends LinkEntity { * Creates a new AMQP receiver under a new AMQP session. */ private async _init(abortSignal?: AbortSignalLike): Promise { - const connectionId = this._context.connectionId; try { const options = this._createMessageSessionOptions(); await this.initLink(options, abortSignal); @@ -284,7 +275,7 @@ export class MessageSession extends LinkEntity { description: errorMessage, condition: ErrorNameConditionMapper.SessionCannotBeLockedError }); - logError(error, "[%s] %O", this._context.connectionId, error); + logger.logError(error, this.logPrefix); throw error; } if (this._providedSessionId == null) this.sessionId = receivedSessionId; @@ -292,27 +283,12 @@ export class MessageSession extends LinkEntity { this.link.properties["com.microsoft:locked-until-utc"] ); logger.verbose( - "[%s] Session with id '%s' is locked until: '%s'.", - connectionId, + "%s Session with id '%s' is locked until: '%s'.", + this.logPrefix, this.sessionId, this.sessionLockedUntilUtc.toISOString() ); - logger.verbose( - "[%s] Receiver '%s' for sessionId '%s' has established itself.", - connectionId, - this.name, - this.sessionId - ); - logger.verbose( - "Promise to create the receiver resolved. " + "Created receiver with name: ", - this.name - ); - logger.verbose( - "[%s] Receiver '%s' created with receiver options: %O", - connectionId, - this.name, - options - ); + logger.verbose("%s Receiver created with receiver options: %O", this.logPrefix, options); if (!this._context.messageSessions[this.name]) { this._context.messageSessions[this.name] = this; } @@ -320,13 +296,7 @@ export class MessageSession extends LinkEntity { this._ensureSessionLockRenewal(); } catch (err) { const errObj = translate(err); - logError( - errObj, - "[%s] An error occured while creating the receiver '%s': %O", - this._context.connectionId, - this.name, - errObj - ); + logger.logError(errObj, "%s An error occured while creating the receiver", this.logPrefix); // Fix the unhelpful error messages for the OperationTimeoutError that comes from `rhea-promise`. if ((errObj as MessagingError).code === "OperationTimeoutError") { @@ -386,11 +356,14 @@ export class MessageSession extends LinkEntity { private _providedSessionId: string | undefined, options?: MessageSessionOptions ) { - super(entityPath, entityPath, context, "ms", { + super(entityPath, entityPath, context, "session", logger, { address: entityPath, audience: `${context.config.endpoint}${entityPath}` }); - this._receiverHelper = new ReceiverHelper(() => this.link); + this._receiverHelper = new ReceiverHelper(() => ({ + receiver: this.link, + logPrefix: this.logPrefix + })); if (!options) options = {}; this.autoComplete = false; if (this._providedSessionId != undefined) this.sessionId = this._providedSessionId; @@ -415,39 +388,29 @@ export class MessageSession extends LinkEntity { // setting all the handlers this._onSettled = (context: EventContext) => { - const connectionId = this._context.connectionId; const delivery = context.delivery; - onMessageSettled(connectionId, delivery, this._deliveryDispositionMap); + onMessageSettled(this.logPrefix, delivery, this._deliveryDispositionMap); }; this._notifyError = (error: MessagingError | Error) => { if (this._onError) { this._onError(error); logger.verbose( - "[%s] Notified the user's error handler about the error received by the " + - "Receiver '%s'.", - this._context.connectionId, - this.name + "%s Notified the user's error handler about the error received by the Receiver", + this.logPrefix ); } }; this._onAmqpError = (context: EventContext) => { - const connectionId = this._context.connectionId; const receiverError = context.receiver && context.receiver.error; if (receiverError) { const sbError = translate(receiverError) as MessagingError; if (sbError.code === "SessionLockLostError") { sbError.message = `The session lock has expired on the session with id ${this.sessionId}.`; } - logError( - sbError, - "[%s] An error occurred for Receiver '%s': %O.", - connectionId, - this.name, - sbError - ); + logger.logError(sbError, "%s An error occurred for Receiver", this.logPrefix); this._notifyError(sbError); } }; @@ -457,7 +420,7 @@ export class MessageSession extends LinkEntity { const sessionError = context.session && context.session.error; if (sessionError) { const sbError = translate(sessionError); - logError( + logger.logError( sbError, "[%s] An error occurred on the session for Receiver '%s': %O.", connectionId, @@ -474,7 +437,7 @@ export class MessageSession extends LinkEntity { const receiver = this.link || context.receiver!; if (receiverError) { const sbError = translate(receiverError) as MessagingError; - logError( + logger.logError( sbError, "[%s] 'receiver_close' event occurred for receiver '%s' for sessionId '%s'. " + "The associated error is: %O", @@ -488,49 +451,42 @@ export class MessageSession extends LinkEntity { } if (receiver && !receiver.isItselfClosed()) { logger.verbose( - "[%s] 'receiver_close' event occurred on the receiver '%s' for sessionId '%s' " + + "%s 'receiver_close' event occurred on the receiver for sessionId '%s' " + "and the sdk did not initiate this. Hence, let's gracefully close the receiver.", - connectionId, - this.name, + this.logPrefix, this.sessionId ); try { await this.close(); } catch (err) { - logError( + logger.logError( err, - "[%s] An error occurred while closing the receiver '%s' for sessionId '%s': %O.", - connectionId, - this.name, - this.sessionId, - err + "%s An error occurred while closing the receiver for sessionId '%s'.", + this.logPrefix, + this.sessionId ); } } else { logger.verbose( - "[%s] 'receiver_close' event occurred on the receiver '%s' for sessionId '%s' " + + "%s 'receiver_close' event occurred on the receiver for sessionId '%s' " + "because the sdk initiated it. Hence no need to gracefully close the receiver", - connectionId, - this.name, + this.logPrefix, this.sessionId ); } }; this._onSessionClose = async (context: EventContext) => { - const connectionId = this._context.connectionId; const receiver = this.link || context.receiver!; const sessionError = context.session && context.session.error; if (sessionError) { const sbError = translate(sessionError); - logError( + logger.logError( sbError, - "[%s] 'session_close' event occurred for receiver '%s' for sessionId '%s'. " + - "The associated error is: %O", - connectionId, - this.name, - this.sessionId, - sbError + "%s 'session_close' event occurred for receiver for sessionId '%s'. " + + "The associated error is", + this.logPrefix, + this.sessionId ); // no need to notify the user's error handler since rhea guarantees that session_error // will always be emitted before session_close. @@ -538,30 +494,26 @@ export class MessageSession extends LinkEntity { if (receiver && !receiver.isSessionItselfClosed()) { logger.verbose( - "[%s] 'session_close' event occurred on the receiver '%s' for sessionId '%s' " + + "%s 'session_close' event occurred on the receiver for sessionId '%s' " + "and the sdk did not initiate this. Hence, let's gracefully close the receiver.", - connectionId, - this.name, + this.logPrefix, this.sessionId ); try { await this.close(); } catch (err) { - logError( + logger.logError( err, - "[%s] An error occurred while closing the receiver '%s' for sessionId '%s': %O.", - connectionId, - this.name, - this.sessionId, - err + "%s An error occurred while closing the receiver for sessionId '%s'", + this.logPrefix, + this.sessionId ); } } else { logger.verbose( - "[%s] 'session_close' event occurred on the receiver '%s' for sessionId '%s' " + + "%s 'session_close' event occurred on the receiver for sessionId'%s' " + "because the sdk initiated it. Hence no need to gracefully close the receiver", - connectionId, - this.name, + this.logPrefix, this.sessionId ); } @@ -576,21 +528,20 @@ export class MessageSession extends LinkEntity { this._isReceivingMessagesForSubscriber = false; if (this._sessionLockRenewalTimer) clearTimeout(this._sessionLockRenewalTimer); logger.verbose( - "[%s] Cleared the timers for 'no new message received' task and " + + "%s Cleared the timers for 'no new message received' task and " + "'session lock renewal' task.", - this._context.connectionId + this.logPrefix ); await super.close(); await this._batchingReceiverLite.close(); } catch (err) { - logError( + logger.logError( err, - "[%s] An error occurred while closing the message session with id '%s': %O.", - this._context.connectionId, - this.sessionId, - err + "%s An error occurred while closing the message session with id '%s'", + this.logPrefix, + this.sessionId ); } } @@ -601,9 +552,8 @@ export class MessageSession extends LinkEntity { isOpen(): boolean { const result: boolean = this.link! && this.link!.isOpen(); logger.verbose( - "[%s] Receiver '%s' for sessionId '%s' is open? -> %s", - this._context.connectionId, - this.name, + "%s Receiver for sessionId '%s' is open? -> %s", + this.logPrefix, this.sessionId, result ); @@ -640,7 +590,6 @@ export class MessageSession extends LinkEntity { this.autoComplete = options.autoComplete === false ? options.autoComplete : true; this._onMessage = onMessage; this._onError = onError; - const connectionId = this._context.connectionId; if (this.link && this.link.isOpen()) { const onSessionMessage = async (context: EventContext): Promise => { @@ -651,10 +600,9 @@ export class MessageSession extends LinkEntity { (!this.link || !this.link.isOpen()) ) { logger.verbose( - "[%s] Not calling the user's message handler for the current message " + - "as the receiver '%s' is closed", - connectionId, - this.name + "%s Not calling the user's message handler for the current message " + + "as the receiver is closed", + this.logPrefix ); return; } @@ -673,14 +621,12 @@ export class MessageSession extends LinkEntity { } catch (err) { // This ensures we call users' error handler when users' message handler throws. if (!isAmqpError(err)) { - logError( + logger.logError( err, - "[%s] An error occurred while running user's message handler for the message " + - "with id '%s' on the receiver '%s': %O", - connectionId, - bMessage.messageId, - this.name, - err + "%s An error occurred while running user's message handler for the message " + + "with id '%s' on the receiver", + this.logPrefix, + bMessage.messageId ); this._onError!(err); } @@ -693,25 +639,21 @@ export class MessageSession extends LinkEntity { this.isOpen() // only try to abandon the messages if the connection is still open ) { try { - logError( + logger.logError( error, - "[%s] Abandoning the message with id '%s' on the receiver '%s' since " + - "an error occured: %O.", - connectionId, - bMessage.messageId, - this.name, - error + "%s Abandoning the message with id '%s' on the receiver since an error occured", + this.logPrefix, + bMessage.messageId ); await bMessage.abandon(); } catch (abandonError) { const translatedError = translate(abandonError); - logError( + logger.logError( translatedError, - "[%s] An error occurred while abandoning the message with id '%s' on the " + - "receiver '%s': %O.", - connectionId, + "%s An error occurred while abandoning the message with id '%s' on the " + + "receiver", + this.logPrefix, bMessage.messageId, - this.name, translatedError ); this._notifyError(translatedError); @@ -731,22 +673,18 @@ export class MessageSession extends LinkEntity { ) { try { logger.verbose( - "[%s] Auto completing the message with id '%s' on " + "the receiver '%s'.", - connectionId, - bMessage.messageId, - this.name + "%s Auto completing the message with id '%s' on the receiver.", + this.logPrefix, + bMessage.messageId ); await bMessage.complete(); } catch (completeError) { const translatedError = translate(completeError); - logError( + logger.logError( translatedError, - "[%s] An error occurred while completing the message with id '%s' on the " + - "receiver '%s': %O.", - connectionId, - bMessage.messageId, - this.name, - translatedError + "%s An error occurred while completing the message with id '%s' on the " + "receiver", + this.logPrefix, + bMessage.messageId ); this._notifyError(translatedError); } @@ -789,13 +727,7 @@ export class MessageSession extends LinkEntity { userAbortSignal }); } catch (error) { - logError( - error, - "[%s] Receiver '%s': Rejecting receiveMessages() with error %O: ", - this._context.connectionId, - this.name, - error - ); + logger.logError(error, `${this.logPrefix} Rejecting receiveMessages() with error`); throw error; } } diff --git a/sdk/servicebus/service-bus/src/util/atomXmlHelper.ts b/sdk/servicebus/service-bus/src/util/atomXmlHelper.ts index 5ee877d2d4b8..93efdd86522b 100644 --- a/sdk/servicebus/service-bus/src/util/atomXmlHelper.ts +++ b/sdk/servicebus/service-bus/src/util/atomXmlHelper.ts @@ -15,11 +15,10 @@ import { } from "@azure/core-http"; import * as Constants from "./constants"; -import { logger } from "../log"; +import { administrationLogger as logger } from "../log"; import { Buffer } from "buffer"; import { parseURL } from "./parseUrl"; -import { logError } from "./errors"; /** * @internal @@ -85,7 +84,7 @@ export async function executeAtomXmlOperation( stripRequest(response.request), stripResponse(response) ); - logError(err, "Error parsing response body from Service - %0", err); + logger.logError(err, "Error parsing response body from Service"); throw error; } diff --git a/sdk/servicebus/service-bus/src/util/errors.ts b/sdk/servicebus/service-bus/src/util/errors.ts index ef8246e79422..e537b7eb647d 100644 --- a/sdk/servicebus/service-bus/src/util/errors.ts +++ b/sdk/servicebus/service-bus/src/util/errors.ts @@ -1,10 +1,9 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT license. -import { logErrorStackTrace, logger } from "../log"; +import { logger } from "../log"; import Long from "long"; import { ConnectionContext } from "../connectionContext"; -import { AmqpError } from "rhea-promise"; /** * Error message to use when EntityPath in connection string does not match the @@ -198,29 +197,3 @@ export function throwTypeErrorIfParameterIsEmptyString( export function getErrorMessageNotSupportedInReceiveAndDeleteMode(failedToDo: string): string { return `Failed to ${failedToDo} as the operation is only supported in 'PeekLock' receive mode.`; } - -/** - * @internal - * @ignore - */ -export function logError(err: Error | AmqpError | undefined, ...args: any[]): void { - let l: typeof logger.info; - - if (isError(err) && err.name === "AbortError") { - l = logger.info; - } else { - l = logger.warning; - } - - l(...args); - - logErrorStackTrace(err); -} - -/** - * @internal - * @ignore - */ -function isError(err: Error | AmqpError | undefined): err is Error { - return err != null && (err as any).name != null; -} diff --git a/sdk/servicebus/service-bus/src/util/utils.ts b/sdk/servicebus/service-bus/src/util/utils.ts index e05e2e3c89fe..72a7090180f6 100644 --- a/sdk/servicebus/service-bus/src/util/utils.ts +++ b/sdk/servicebus/service-bus/src/util/utils.ts @@ -2,7 +2,7 @@ // Licensed under the MIT license. import Long from "long"; -import { logger } from "../log"; +import { logger, receiverLogger, messageLogger } from "../log"; import { OperationTimeoutError, generate_uuid } from "rhea-promise"; import isBuffer from "is-buffer"; import { Buffer } from "buffer"; @@ -91,15 +91,15 @@ export function calculateRenewAfterDuration(lockedUntilUtc: Date): number { const now = Date.now(); const lockedUntil = lockedUntilUtc.getTime(); const remainingTime = lockedUntil - now; - logger.verbose("Locked until utc : %d", lockedUntil); - logger.verbose("Current time is : %d", now); - logger.verbose("Remaining time is : %d", remainingTime); + receiverLogger.verbose("Locked until utc : %d", lockedUntil); + receiverLogger.verbose("Current time is : %d", now); + receiverLogger.verbose("Remaining time is : %d", remainingTime); if (remainingTime < 1000) { return 0; } const buffer = Math.min(remainingTime / 2, 10000); // 10 seconds const renewAfter = remainingTime - buffer; - logger.verbose("Renew after : %d", renewAfter); + receiverLogger.verbose("Renew after : %d", renewAfter); return renewAfter; } @@ -152,7 +152,7 @@ export function getProcessorCount(): number { */ export function toBuffer(input: any): Buffer { let result: any; - logger.verbose( + messageLogger.verbose( "[utils.toBuffer] The given message body that needs to be converted to buffer is: ", input ); @@ -171,11 +171,11 @@ export function toBuffer(input: any): Buffer { `An error occurred while executing JSON.stringify() on the given input ` + input + `${err instanceof Error ? err.stack : JSON.stringify(err)}`; - logger.warning("[utils.toBuffer] " + msg); + messageLogger.warning("[utils.toBuffer] " + msg); throw err instanceof Error ? err : new Error(msg); } } - logger.verbose("[utils.toBuffer] The converted buffer is: %O.", result); + messageLogger.verbose("[utils.toBuffer] The converted buffer is: %O.", result); return result; } diff --git a/sdk/servicebus/service-bus/test/internal/errors.spec.ts b/sdk/servicebus/service-bus/test/internal/errors.spec.ts index d33a23703e20..099bbdcdd7db 100644 --- a/sdk/servicebus/service-bus/test/internal/errors.spec.ts +++ b/sdk/servicebus/service-bus/test/internal/errors.spec.ts @@ -2,12 +2,11 @@ // Licensed under the MIT license. import * as sinon from "sinon"; -import { logger } from "../../src/log"; -import { logError } from "../../src/util/errors"; import { MessagingError } from "@azure/core-amqp"; import { AbortError } from "@azure/abort-controller"; import chai from "chai"; import chaiAsPromised from "chai-as-promised"; +import { createServiceBusLogger } from "../../src/log"; chai.use(chaiAsPromised); const assert = chai.assert; @@ -15,6 +14,7 @@ describe("errors", () => { let verboseSpy: sinon.SinonSpy; let warningSpy: sinon.SinonSpy; let infoSpy: sinon.SinonSpy; + const logger = createServiceBusLogger("test"); before(() => { verboseSpy = sinon.spy(logger, "verbose"); @@ -30,7 +30,7 @@ describe("errors", () => { [new Error(), new MessagingError("message")].forEach((err, i) => { it(`normal errors go to warning[${i}]`, () => { - logError(err); + logger.logError(err, "this is a message"); assert.isTrue(warningSpy.calledOnce, "errors are logged to the .warning stream by default"); assert.isFalse( @@ -41,11 +41,16 @@ describe("errors", () => { verboseSpy.calledOnce, "verbose is used for the stack trace when it's available" ); + + // check that we call the stream with the proper args + assert.equal(warningSpy.args[0][0], "this is a message"); + assert.equal(warningSpy.args[0][1], ":"); + assert.equal(warningSpy.args[0][2].message, err.message); }); }); it("abortErrors go to info", () => { - logError(new AbortError()); + logger.logError(new AbortError()); assert.isFalse(warningSpy.calledOnce, "AbortError's are not sent to warning"); assert.isTrue(infoSpy.calledOnce, "AbortError's are sent to info"); @@ -60,7 +65,7 @@ describe("errors", () => { [stacktraceLessError, undefined].forEach((err, i) => { it(`no stack trace available, skips verbose[${i}]`, () => { - logError(err); + logger.logError(err); assert.isTrue(warningSpy.calledOnce, "logs to warning"); assert.isFalse(infoSpy.calledOnce, "not logged to info."); diff --git a/sdk/servicebus/service-bus/test/internal/linkentity.unittest.spec.ts b/sdk/servicebus/service-bus/test/internal/linkentity.unittest.spec.ts index 6835ce9cdb6d..73fc51a263b2 100644 --- a/sdk/servicebus/service-bus/test/internal/linkentity.unittest.spec.ts +++ b/sdk/servicebus/service-bus/test/internal/linkentity.unittest.spec.ts @@ -9,6 +9,7 @@ import { Receiver, ReceiverOptions } from "rhea-promise"; import sinon from "sinon"; import { ConnectionContext } from "../../src/connectionContext"; import { LinkEntity } from "../../src/core/linkEntity"; +import { receiverLogger } from "../../src/log"; import { isLinkLocked } from "../utils/misc"; import { createConnectionContextForTests, createRheaReceiverForTests } from "./unittestUtils"; chai.use(chaiAsPromised); @@ -30,7 +31,8 @@ describe("LinkEntity unit tests", () => { "some initial name", "some initial name", connectionContext, - "sr", + "streaming", + receiverLogger, { address: "my-address" } @@ -288,7 +290,7 @@ describe("LinkEntity unit tests", () => { name: "some new name" }); - assert.equal(linkEntity["_logPrefix"], "[connection-id|sr:some new name]"); + assert.equal(linkEntity["_logPrefix"], "[connection-id|streaming:some new name]"); // note that specifying a name is a complete override - no additional tacking // on of a GUID or anything happens (that's up to you when you override the @@ -300,7 +302,7 @@ describe("LinkEntity unit tests", () => { ); // we also update the log prefix - assert.equal(linkEntity["_logPrefix"], "[connection-id|sr:some new name]"); + assert.equal(linkEntity["_logPrefix"], "[connection-id|streaming:some new name]"); }); it("multiple closes don't cause errors", async () => { diff --git a/sdk/servicebus/service-bus/test/internal/receiverHelper.spec.ts b/sdk/servicebus/service-bus/test/internal/receiverHelper.spec.ts index 5d03b8e892e5..01b2938327ce 100644 --- a/sdk/servicebus/service-bus/test/internal/receiverHelper.spec.ts +++ b/sdk/servicebus/service-bus/test/internal/receiverHelper.spec.ts @@ -28,7 +28,10 @@ describe("ReceiverHelper unit tests", () => { * checking. */ it(`operations on an invalid receiver should just no-op harmlessly: ${invalidReceiver}`, async () => { - const helper = new ReceiverHelper(() => invalidReceiver); + const helper = new ReceiverHelper(() => ({ + receiver: invalidReceiver, + logPrefix: "whatever" + })); assert.isFalse(helper.addCredit(101)); await helper.drain(); @@ -52,7 +55,7 @@ describe("ReceiverHelper unit tests", () => { it("operations on an open receiver", async () => { const receiver = createRheaReceiverForTests(); - const helper = new ReceiverHelper(() => receiver); + const helper = new ReceiverHelper(() => ({ receiver, logPrefix: "hello" })); let drainWasCalled = false; diff --git a/sdk/servicebus/service-bus/test/internal/shared.spec.ts b/sdk/servicebus/service-bus/test/internal/shared.spec.ts index 87891a3c820b..deb98b0ce0d1 100644 --- a/sdk/servicebus/service-bus/test/internal/shared.spec.ts +++ b/sdk/servicebus/service-bus/test/internal/shared.spec.ts @@ -4,32 +4,34 @@ import { getMessageIterator, wrapProcessErrorHandler } from "../../src/receivers/shared"; import chai from "chai"; import { ServiceBusReceiver } from "../../src/receivers/receiver"; +import { ServiceBusLogger } from "../../src/log"; const assert = chai.assert; describe("shared", () => { it("error handler wrapper", () => { - const loggedMessages: string[] = []; + let logErrorCalled = false; const wrappedProcessError = wrapProcessErrorHandler( { - processError: () => { + processError: (err) => { + assert.equal(err.message, "Actual error that was passed in from service bus to the user"); throw new Error("Whoops!"); } }, - (msg) => { - loggedMessages.push(msg); - } + { + logError: (err: Error, msg) => { + // we only call this if the user's callback throws an error - we don't funnel this back + // into their processError because that could cause an infinite set of failures. + assert.equal(msg, `An error was thrown from the user's processError handler`); + assert.equal(err.toString(), "Error: Whoops!"); + logErrorCalled = true; + } + } as ServiceBusLogger ); - wrappedProcessError( - new Error( - "Doesn't matter, testing internal behavior when the user's process error handler throws" - ) - ); + wrappedProcessError(new Error("Actual error that was passed in from service bus to the user")); - assert.deepEqual(loggedMessages, [ - `An error was thrown from the user's processError handler: Error: Whoops!` - ]); + assert.isTrue(logErrorCalled, "log error should have been called"); }); it("getMessageIterator doesn't yield empty responses", async () => {