feat: add order log (#338)

packages/network-support/src/fetch.ts

@@ -76,7 +76,10 @@ export function createFetch(
       }
       let requestParams;
       if (retries < maxRetries) {
-        requestParams = await orderManager.getRequestParams(requestId, proxyVersion);
+        requestParams = await orderManager.getRequestParams(requestId, proxyVersion, {
+          rid,
+          retries,
+        });
       }
       if (!requestParams) {
         if (orderManager.fallbackServiceUrl && !triedFallback) {

packages/network-support/src/orderManager.ts

@@ -114,7 +114,7 @@ export class OrderManager {
       apikey,
       stateStore,
     });
-    this._init = this.refreshOrders();
+    this._init = this.refreshOrders('init');
     // eslint-disable-next-line @typescript-eslint/no-misused-promises
     this.timer = setInterval(() => this.refreshOrders(), this.interval);
     this.selector = selector;
@@ -158,9 +158,14 @@ export class OrderManager {
     return this.options.fallbackServiceUrl;
   }
 
-  private async refreshOrders() {
-    try {
-      const orders = await fetchOrders(this.authUrl, this.projectId, this.projectType, this.apikey);
+  private async refreshOrders(phase?: string) {
+    const { valid, statusCode, orders, resData, error, stack } = await fetchOrders(
+      this.authUrl,
+      this.projectId,
+      this.projectType,
+      this.apikey
+    );
+    if (valid) {
       if (orders.agreements && orders.agreements.length > 0) {
         this._agreements = orders.agreements;
       }
@@ -170,11 +175,19 @@ export class OrderManager {
         void this.updatePriceScore(orders.plans);
       }
       this.healthy = true;
-    } catch (e) {
-      // it seems cannot reach this code, fetchOrders already handle the errors.
-      this.logger?.error(`fetch orders failed: ${String(e)}`);
-      this.healthy = false;
+      return;
     }
+
+    this.logger?.error({
+      type: 'orders_fetch',
+      deploymentId: this.projectId,
+      phase: phase || 'default',
+      statusCode,
+      resData,
+      error,
+      stack,
+    });
+    this.healthy = false;
   }
 
   private async filterOrdersByRequestId(requestId: string, orders: Order[]) {
@@ -192,10 +205,11 @@ export class OrderManager {
 
   async getRequestParams(
     requestId: string,
-    proxyVersion?: string
+    proxyVersion?: string,
+    logData?: any
   ): Promise<RequestParam | undefined> {
     const innerRequest = async () => {
-      const order = await this.getNextOrder(requestId, proxyVersion);
+      const order = await this.getNextOrder(requestId, proxyVersion, logData);
       const headers: RequestParam['headers'] = {};
       if (order) {
         headers['X-SQ-No-Resp-Sig'] = 'true';
@@ -360,14 +374,15 @@ export class OrderManager {
 
   private async getNextOrder(
     requestId: string,
-    proxyVersion?: string
+    proxyVersion?: string,
+    logData?: any
   ): Promise<OrderWithType | undefined> {
     await this._init;
     const agreementsOrders = await this.getNextAgreement(requestId, proxyVersion);
     if (agreementsOrders) {
       return { ...agreementsOrders, type: OrderType.agreement };
     }
-    const flexPlanOrders = await this.getNextPlan(requestId, proxyVersion);
+    const flexPlanOrders = await this.getNextPlan(requestId, proxyVersion, logData);
     if (flexPlanOrders) {
       return { ...flexPlanOrders, type: OrderType.flexPlan };
     }
@@ -406,21 +421,39 @@ export class OrderManager {
 
   private async getNextPlan(
     requestId: string,
-    proxyVersion?: string
+    proxyVersion?: string,
+    logData?: any
   ): Promise<FlexPlanOrder | undefined> {
     await this._init;
 
     if (!this.plans) return;
 
-    this.logger?.debug(`available plans: ${this.plans.length}`);
+    logData = logData || {};
+    // this.logger?.debug(`available plans: ${this.plans.length}`);
+    this.logger?.info({
+      type: 'plans_init',
+      deploymentId: this.projectId,
+      requestId,
+      plansLen: this.plans.length,
+      ...logData,
+    });
+
     let plans = await this.filterOrdersByRequestId(requestId, this.plans);
-    this.logger?.debug(`available plans after filter: ${plans.length}`);
+    // this.logger?.debug(`available plans after filter: ${plans.length}`);
 
     if (proxyVersion && plans?.length) {
       plans = this.filterOrdersByProxyVersion(plans, proxyVersion);
-      this.logger?.debug(`available plans after proxy version filter: ${plans.length}`);
+      // this.logger?.debug(`available plans after proxy version filter: ${plans.length}`);
     }
 
+    this.logger?.info({
+      type: 'plans_filter',
+      deploymentId: this.projectId,
+      requestId,
+      plansLen: plans.length,
+      ...logData,
+    });
+
     if (!plans?.length) return;
 
     const plan = await this.selectRunner(plans);
@@ -429,6 +462,14 @@ export class OrderManager {
       await this.updateSelectedRunner(requestId, plan.indexer);
     }
 
+    this.logger?.info({
+      type: 'plans_final',
+      deploymentId: this.projectId,
+      requestId,
+      plansLen: plans.length,
+      ...logData,
+    });
+
     return plan;
   }
 

packages/network-support/src/utils/query.ts

@@ -62,6 +62,15 @@ export async function GET<T>(url: string): Promise<T> {
   return res.json();
 }
 
+export async function RAW_GET<T>(url: string): Promise<Response> {
+  const headers = { 'Content-Type': 'application/json' };
+  const res = await customFetch(url, {
+    method: 'get',
+    headers,
+  });
+  return res;
+}
+
 interface OrdersResponse {
   agreements: ServiceAgreementOrder[];
   plans: FlexPlanOrder[];
@@ -73,13 +82,36 @@ export async function fetchOrders(
   projectType: ProjectType,
   apikey?: string
 ) {
+  let statusCode = 0;
   try {
     const ordersURL = new URL(`/orders/${projectType}/${projectId}`, authUrl);
     if (apikey) {
       ordersURL.searchParams.append('apikey', apikey);
     }
-    return await GET<OrdersResponse>(ordersURL.toString());
-  } catch {
-    return { agreements: [], plans: [] };
+    const res = await RAW_GET<OrdersResponse>(ordersURL.toString());
+    statusCode = res.status;
+
+    if (statusCode >= 400) {
+      const resData = await res.text();
+      return {
+        valid: false,
+        statusCode,
+        resData,
+      };
+    }
+
+    const data = await res.json();
+    return {
+      valid: true,
+      statusCode,
+      orders: data,
+    };
+  } catch (e: any) {
+    return {
+      valid: false,
+      statusCode,
+      error: e.message,
+      stack: e.stack,
+    };
   }
 }