Cwmp service failed with "Database clock skew too great" log

1

I am using GenieACS version 1.2.8 with modular deployment (2 nodes of GenieACS and 3 nodes of MongoDB replica set). It was fine for a long time until the day I met the genieacs-cwmp service failed issue with the below error logs

acs01 genieacs-cwmp: 2023-10-22T02:35:23.982Z [ERROR] Uncaught exception; pid=61527 exceptionName="Error" exceptionMessage="Database clock skew too great" exceptionStack="Error: Database clock skew too great\n    at async (/usr/lib/node_modules/lib/cache.ts:87:13)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async (/usr/lib/node_modules/lib/cwmp.ts:214:41)"
acs01 genieacs-cwmp: 2023-10-22T02:35:32.479Z [ERROR] Uncaught exception; pid=61902 exceptionName="MongoNotConnectedError" exceptionMessage="MongoClient must be connected to perform this operation" exceptionStack="/usr/lib/node_modules/genieacs/node_modules/mongodb/src/utils.ts:476\n  throw new MongoNotConnectedError('MongoClient must be connected to perform this operation');\n        ^\n\nMongoNotConnectedError: MongoClient must be connected to perform this operation\n    at Object.getTopology (/usr/lib/node_modules/genieacs/node_modules/mongodb/src/utils.ts:476:9)\n    at Collection.deleteOne (/usr/lib/node_modules/genieacs/node_modules/mongodb/src/collection.ts:570:7)\n    at async (/usr/lib/node_modules/lib/cache.ts:113:37)\n    at async (/usr/lib/node_modules/lib/cwmp.ts:828:9)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async (/usr/lib/node_modules/lib/cwmp.ts:207:29)"

I just took a quick look at the source code that contains the above printed logs (genieacs/lib/cache.ts)

export async function acquireLock(
  lockName: string,
  ttl: number,
  timeout = 0,
  token = Math.random().toString(36).slice(2)
): Promise<string> {
  try {
    const now = Date.now();
    const r = await cacheCollection.findOneAndUpdate(
      { _id: lockName, value: token },
      {
        $set: {
          expire: new Date(now + ttl + CLOCK_SKEW_TOLERANCE),
        },
        $currentDate: { timestamp: true },
      },
      { upsert: true, returnDocument: "after" }
    );
    if (Math.abs(r.value.timestamp.getTime() - now) > CLOCK_SKEW_TOLERANCE)
      throw new Error("Database clock skew too great");
  } catch (err) {
    if (err.code !== 11000) throw err;
    if (!(timeout > 0)) return null;
    const w = 50 + Math.random() * 50;
    await new Promise((resolve) => setTimeout(resolve, w));
    return acquireLock(lockName, ttl, timeout - w, token);
  }

  return token;
}

So, what is the meaning of CLOCK_SKEW_TOLERANCE in this code block?
And, could anyone give me an example of when could “Database clock skew too great” happen?

Thank you so much~

2

@akcoder and @rudymartin
Would you please take a look at this and share your opinion?
Thank you so much~

3

No.

5 Likes
4

Hi @harilam, did you find a solution for this?

5

Hi Felipe,
I think I already figured out the problem with my production environment.
My production run a cron job to get all devices’ information periodically via NBI and this is the main cause of the exceptionName=“Error” exceptionMessage=“Database clock skew too great” and exceptionName=“MongoNotConnectedError” exceptionMessage=“MongoClient must be connected to perform this operation”. So, mongoDB high load is the main cause of this problem.
I just add some delay and reduce the number of devices / each request from my cron job and now problem disappeared.

For others: please check the mongoDB read/write statistics (using Studio3T) when problem happen and identify the source of problem in your environment.

1 Like
6

Oh, got it.
Thank you so much for answer.