Skip to content

PoshBot seems to be running a job that uses high CPU #203

@pauby

Description

@pauby

I'm not actually sure what's happening this one so I'm raising the issue to see if I can get more info on how to troubleshoot it and confirm it's related to PoshBot.

I recently deployed the commit from this issue. Ever since then, at approximately the same time (within a couple of hours) a PowerShell session get's spawned that consumes a high amount of CPU. Our monitoring system then is alerting us that the CPU is being pegged at 100%. When I log in I see the following:

image

Some things to note:

  1. The job is running under the same user as PoshBot (which runs under it's own username and only Poshbot 'stuff' runs under it);
  2. PoshBot runs in a PowerShell session and not as a service. The session does not have administrator privileges;
  3. There are no scheduled tasks set to run under the same account as PoshBot;
  4. This has only started happening since I deployed the commit from this issue;
  5. I'm using PoshBot with Slack exclusively;

Now this could just be any PowerShell session, however when I terminate that process I get this in PoshBot:

WARNING: {"DataTime":"2020-02-14
11:19:39Z","Class":"SlackConnection","Method":"ReadReceiveJob","Severity":"Warning","LogLevel":"Info","Message":"Receive job state is [Failed]. Attempting to reconnect...","Data":{}}

So it looks like a job running in PoshBot. However when I run get-schedule for PoshBot I get this:

image

The two jobs that run every day both run without problems. So it's not them. The 30 day one isn't due to run yet.

There is little in the PoshBot logs, however I do notice this at approximately the time the alerts come through about high CPU:

{"DataTime":"2020-02-13 18:18:53Z","Class":"SlackBackend","Method":"ReceiveMessage","Severity":"Normal","LogLevel":"Debug","Message":"Received message","Data":"{\"type\": \"goodbye\", \"source\": \"gateway_server\"}"}
{"DataTime":"2020-02-13 18:18:53Z","Class":"SlackBackend","Method":"ReceiveMessage","Severity":"Normal","LogLevel":"Debug","Message":"Message type is [goodbye]. Ignoring","Data":{}}

And finally, in the event logs of the server I get this at 18:18:15:

The WMI Performance Adapter service entered the running state.

and at 18:24:16:

The WMI Performance Adapter service entered the stopped state.

I only add the event logs as I've seen spike when WMI misbehaves but I'm not sure if this is also a red herring.

The logs are at 'DEBUG' level and there is not much in there. So I'm looking to find out if:

  1. The job that is running is for PoshBot (looks like it is);
  2. How to identify if this is an internal PoshBot job that's gone rogue or something else;
  3. Something else?!

The only step left to me was to stop PoshBot from running and to see if that session runs again.

(apologies I didn't complete the issue template as this was much more than that).

Your Environment

  • Module version used: 0.12.0 from here
  • Operating System and PowerShell version: $PsVersionTable:
Name                           Value
----                           -----
PSVersion                      5.1.14409.1005
PSEdition                      Desktop
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0...}
BuildVersion                   10.0.14409.1005
CLRVersion                     4.0.30319.42000
WSManStackVersion              3.0
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1

Metadata

Metadata

Assignees

Labels

bugpinnedPrevent closing if stale

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions