osschat icon indicating copy to clipboard operation
osschat copied to clipboard

Restart service when bot is off - [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.

Open hailiang-wang opened this issue 2 years ago • 2 comments

Service does not work, with following trace.

 21:00:54 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | ERROR (server):
osschat_1  |     type: "error"
osschat_1  | INFO (server): Connected
osschat_1  | 21:09:33 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 21:18:12 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 21:26:51 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 21:35:30 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 21:44:09 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 21:52:48 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 22:01:27 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 22:10:06 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 22:18:45 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 22:27:24 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 22:36:02 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 22:44:41 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 22:53:20 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.                                                     osschat_1  | 23:01:59 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.                                                     osschat_1  | 23:10:38 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 23:19:17 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 23:27:56 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 23:36:35 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 23:45:14 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 23:53:53 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 00:02:32 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 00:11:10 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 00:17:44 INFO Chatops roomMessage(21588818228@chatroom, https://github.com/chatopera/cskefu/issues/480#issuecomment-933057883)
osschat_1  | 00:17:44 ERR Chatops roomMessage() this.bot is offline
osschat_1  | 00:17:44 INFO Chatops roomMessage(21588818228@chatroom, UrlLink<https://github.com/chatopera/cskefu/issues/480#issuecomment-933057883>)
osschat_1  | 00:17:44 ERR Chatops roomMessage() this.bot is offline
osschat_1  | INFO (http): POST / 200 - 19ms
osschat_1  | INFO (server): POST http://localhost:3000/ - 200
osschat_1  | INFO (http): POST / 200 - 0ms
osschat_1  | INFO (server): POST http://localhost:3000/ - 200
osschat_1  | 00:19:49 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 00:19:55 INFO Config registering process.on("unhandledRejection") for development/debug
osschat_1  | 00:19:55 VERB Config constructor()
osschat_1  | 00:19:55 VERB Wechaty init() getRavenDsn() return undefined, skipped.
osschat_1  | 00:19:55 VERB wechaty-puppet-service monkeyPatchMetadataFromHttp2Headers()
osschat_1  | 00:19:55 VERB ResolverWechaty setup()
osschat_1  | 00:19:55 VERB getWechaty getHAWechaty()
osschat_1  | 00:19:55 VERB getMemory getMemory(heroku-wechaty)
osschat_1  | 00:19:55 VERB getMemory getMemory() creating new file memory
osschat_1  | 00:19:55 VERB MemoryCard constructor({"name":"heroku-wechaty"})

Describe the solution you'd like

When OSSChat is restarted, the bot is up and works.

Auto detect the error and exit, as later the server would auto restart with some monitor.

hailiang-wang avatar Oct 04 '21 00:10 hailiang-wang

It's very hard to understand the program situation without any reproducible steps.

HAWechaty definitely has lots of bugs (it's still WIP), and the PuppetPadlocal has issues sometimes too.

If we find any reproducible steps, I'd like to dig into them and see what happens.

huan avatar Oct 04 '21 05:10 huan

更多日志

osschat_1  |     at /app/node_modules/rxjs/dist/cjs/internal/operators/observeOn.js:10:197
osschat_1  |     at QueueAction.work (/app/node_modules/rxjs/dist/cjs/internal/util/executeSchedule.js:8:9)
osschat_1  |     at QueueAction.AsyncAction._execute (/app/node_modules/rxjs/dist/cjs/internal/scheduler/AsyncAction.js:76:18)
osschat_1  |     at QueueAction.execute (/app/node_modules/rxjs/dist/cjs/internal/scheduler/QueueAction.js:41:18)
osschat_1  |     at QueueScheduler.AsyncScheduler.flush (/app/node_modules/rxjs/dist/cjs/internal/scheduler/AsyncScheduler.js:39:33)
osschat_1  |     at QueueAction.schedule (/app/node_modules/rxjs/dist/cjs/internal/scheduler/QueueAction.js:35:24)
osschat_1  |     at QueueScheduler.Scheduler.schedule (/app/node_modules/rxjs/dist/cjs/internal/Scheduler.js:13:57)
osschat_1  |     at Object.executeSchedule (/app/node_modules/rxjs/dist/cjs/internal/util/executeSchedule.js:7:42)
osschat_1  |     at /app/node_modules/rxjs/dist/cjs/internal/operators/observeOn.js:10:126
osschat_1  |     at OperatorSubscriber._this._next (/app/node_modules/rxjs/dist/cjs/internal/operators/OperatorSubscriber.js:28:21)
osschat_1  |     at OperatorSubscriber.Subscriber.next (/app/node_modules/rxjs/dist/cjs/internal/Subscriber.js:72:18)
osschat_1  |     at /app/node_modules/rxjs/dist/cjs/internal/operators/mergeInternals.js:28:28
osschat_1  |     at OperatorSubscriber._this._next (/app/node_modules/rxjs/dist/cjs/internal/operators/OperatorSubscriber.js:28:21)
osschat_1  |     at OperatorSubscriber.Subscriber.next (/app/node_modules/rxjs/dist/cjs/internal/Subscriber.js:72:18)
osschat_1  |     at /app/node_modules/rxjs/dist/cjs/internal/operators/mergeInternals.js:28:28
osschat_1  |     at OperatorSubscriber._this._next (/app/node_modules/rxjs/dist/cjs/internal/operators/OperatorSubscriber.js:28:21)
osschat_1  |     at OperatorSubscriber.Subscriber.next (/app/node_modules/rxjs/dist/cjs/internal/Subscriber.js:72:18)
osschat_1  |     at /app/node_modules/rxjs/dist/cjs/internal/operators/mergeInternals.js:28:28
osschat_1  |     at OperatorSubscriber._this._next (/app/node_modules/rxjs/dist/cjs/internal/operators/OperatorSubscriber.js:28:21)
osschat_1  |     at OperatorSubscriber.Subscriber.next (/app/node_modules/rxjs/dist/cjs/internal/Subscriber.js:72:18)
osschat_1  |     at /app/node_modules/rxjs/dist/cjs/internal/operators/switchMap.js:17:190
osschat_1  |     at OperatorSubscriber._this._next (/app/node_modules/rxjs/dist/cjs/internal/operators/OperatorSubscriber.js:28:21)
osschat_1  |     at OperatorSubscriber.Subscriber.next (/app/node_modules/rxjs/dist/cjs/internal/Subscriber.js:72:18)
osschat_1  |     at /app/node_modules/rxjs/dist/cjs/internal/operators/mergeInternals.js:28:28
osschat_1  |     at OperatorSubscriber._this._next (/app/node_modules/rxjs/dist/cjs/internal/operators/OperatorSubscriber.js:28:21)
osschat_1  |     at OperatorSubscriber.Subscriber.next (/app/node_modules/rxjs/dist/cjs/internal/Subscriber.js:72:18)
osschat_1  |     at /app/node_modules/rxjs/dist/cjs/internal/operators/map.js:10:24
osschat_1  |     at OperatorSubscriber._this._next (/app/node_modules/rxjs/dist/cjs/internal/operators/OperatorSubscriber.js:28:21)
osschat_1  |     at OperatorSubscriber.Subscriber.next (/app/node_modules/rxjs/dist/cjs/internal/Subscriber.js:72:18)
osschat_1  |     at AsyncAction.work (/app/node_modules/rxjs/dist/cjs/internal/observable/timer.js:28:28)
osschat_1  |     at AsyncAction._execute (/app/node_modules/rxjs/dist/cjs/internal/scheduler/AsyncAction.js:76:18)
osschat_1  |     at AsyncAction.execute (/app/node_modules/rxjs/dist/cjs/internal/scheduler/AsyncAction.js:64:26)
osschat_1  |     at AsyncScheduler.flush (/app/node_modules/rxjs/dist/cjs/internal/scheduler/AsyncScheduler.js:39:33)
osschat_1  |     at listOnTimeout (internal/timers.js:557:17)
osschat_1  |     at processTimers (internal/timers.js:500:7)
osschat_1  | 06:28:42 VERB StateSwitch <PuppetPadlocal> ready(off, noCross=false)
osschat_1  | 06:28:42 WARN [PuppetPadlocal] stop() is called on a OFF puppet. await ready(off) and return.
osschat_1  | 06:29:22 VERB Contact say(ding)
osschat_1  | 06:30:50 VERB Contact say(ding)
osschat_1  | 06:32:18 VERB Contact say(ding)
osschat_1  | 06:33:47 VERB Contact say(ding)

hailiang-wang avatar Oct 09 '21 06:10 hailiang-wang