An error has occurred in PowerShell IPC listening thread

[mtnielsen]

trafficstars

Prerequisites

• [X] Write a descriptive title.
• [X] Make sure you are able to repro it on the latest released version
• [X] Search the existing issues.
• [X] Refer to the FAQ.
• [X] Refer to Differences between Windows PowerShell 5.1 and PowerShell.

Steps to reproduce

Short:

podman run --name moo -dti almalinux:8 /usr/sbin/init
podman exec -ti moo /bin/bash

yum install -yq epel-release
yum upgrade -yq
yum install -yq syslog-ng
curl https://packages.microsoft.com/config/rhel/8/prod.repo | tee /etc/yum.repos.d/microsoft.repo
yum install -yq powershell gssntlmssp
rm -rf /opt/microsoft/powershell/7/Modules/PSReadLine/
echo '{ "LogLevel":"Debug" }' > /opt/microsoft/powershell/7/powershell.config.json
systemctl start syslog-ng
pwsh
exit
tail /var/log/messages

Long:

[root@BUILD nagios]# podman run --name moo -dti almalinux:8 /usr/sbin/init
0220965500cfcd33e8e5574b5c5ec246ecc505cd014581a57770375eb14f8a2d
[root@BUILD nagios]# podman exec -ti moo /bin/bash
[root@0220965500cf /]# yum install -yq epel-release

Installed:
  epel-release-8-10.el8.noarch

[root@0220965500cf /]# yum upgrade -yq

Upgraded:
  almalinux-release-8.5-4.el8.x86_64        binutils-2.30-108.el8_5.1.x86_64       cryptsetup-libs-2.3.3-4.el8_5.1.x86_64     cyrus-sasl-lib-2.1.27-6.el8_5.x86_64    epel-release-8-14.el8.noarch           libgcc-8.5.0-4.el8_5.alma.x86_64
  libstdc++-8.5.0-4.el8_5.alma.x86_64       openssl-libs-1:1.1.1k-5.el8_5.x86_64   platform-python-3.6.8-41.el8.alma.x86_64   python3-libs-3.6.8-41.el8.alma.x86_64   python3-rpm-4.14.3-19.el8_5.2.x86_64   rpm-4.14.3-19.el8_5.2.x86_64
  rpm-build-libs-4.14.3-19.el8_5.2.x86_64   rpm-libs-4.14.3-19.el8_5.2.x86_64      systemd-239-51.el8_5.3.x86_64              systemd-libs-239-51.el8_5.3.x86_64      systemd-pam-239-51.el8_5.3.x86_64      vim-minimal-2:8.0.1763-16.el8_5.4.x86_64
Installed:
  diffutils-3.6-6.el8.x86_64        libxkbcommon-0.9.1-1.el8.x86_64        openssl-1:1.1.1k-5.el8_5.x86_64        openssl-pkcs11-0.4.10-2.el8.x86_64        platform-python-pip-9.0.3-20.el8.noarch        xkeyboard-config-2.28-1.el8.noarch

[root@0220965500cf /]# yum install -yq syslog-ng

Installed:
  ivykis-0.42.4-2.el8.x86_64                   libnet-1.1.6-15.el8.x86_64                   logrotate-3.14.0-4.el8.x86_64                   syslog-ng-3.23.1-2.el8.x86_64                   syslog-ng-logrotate-3.23.1-2.el8.x86_64

[root@0220965500cf /]# curl https://packages.microsoft.com/config/rhel/8/prod.repo | tee /etc/yum.repos.d/microsoft.repo
[root@0220965500cf /]# yum install -yq powershell gssntlmssp

Installed:
  avahi-libs-0.7-20.el8.x86_64            cups-libs-1:2.2.6-40.el8.x86_64 gssntlmssp-0.7.0-6.el8.x86_64     jansson-2.11-3.el8.x86_64     libicu-60.3-2.el8_1.x86_64   libldb-2.3.0-2.el8.x86_64               libtalloc-2.3.2-1.el8.x86_64
  libtdb-1.4.3-1.el8.x86_64               libtevent-0.11.0-0.el8.x86_64   libwbclient-4.14.5-9.el8_5.x86_64 lmdb-libs-0.9.24-1.el8.x86_64 powershell-7.2.1-1.rh.x86_64 samba-client-libs-4.14.5-9.el8_5.x86_64 samba-common-4.14.5-9.el8_5.noarch
  samba-common-libs-4.14.5-9.el8_5.x86_64

[root@0220965500cf /]# rm -rf /opt/microsoft/powershell/7/Modules/PSReadLine/
[root@0220965500cf /]# echo '{ "LogLevel":"Debug" }' > /opt/microsoft/powershell/7/powershell.config.json
[root@0220965500cf /]# cat /opt/microsoft/powershell/7/powershell.config.json
{ "LogLevel":"Debug" }
[root@0220965500cf /]# systemctl start syslog-ng
[root@0220965500cf /]# pwsh
PowerShell 7.2.1
Copyright (c) Microsoft Corporation.

https://aka.ms/powershell
Type 'help' to get help.

PS /> exit
[root@0220965500cf /]# tail /var/log/messages
Mar 10 12:28:17 0220965500cf syslog-ng[413]: syslog-ng: Error setting capabilities, capability management disabled; error='Operation not permitted'
Mar 10 12:28:17 0220965500cf syslog-ng[413]: [2022-03-10T12:28:17.337674] Plugin module not found in 'module-path'; module-path='/usr/lib64/syslog-ng', module='http'
Mar 10 12:28:17 0220965500cf syslog-ng[413]: [2022-03-10T12:28:17.341243] Plugin module not found in 'module-path'; module-path='/usr/lib64/syslog-ng', module='http'
Mar 10 12:28:17 0220965500cf syslog-ng[413]: [2022-03-10T12:28:17.342060] Plugin module not found in 'module-path'; module-path='/usr/lib64/syslog-ng', module='http'
Mar 10 12:28:17 0220965500cf syslog-ng[413]: [2022-03-10T12:28:17.345348] WARNING: With use-dns(no), dns-cache() will be forced to 'no' too!;
Mar 10 12:28:17 0220965500cf systemd[1]: Started System Logger Daemon.
Mar 10 12:28:25 0220965500cf powershell[419]: (7.2.1:1:80) [Perftrack_ConsoleStartupStart:PowershellConsoleStartup.WinStart.Informational] PowerShell console is starting up
Mar 10 12:28:25 0220965500cf powershell[419]: (7.2.1:B:80) [NamedPipeIPC_ServerListenerStarted:NamedPipe.Open.Informational] PowerShell has started an IPC listening thread on process: 419 in AppDomain: None.
Mar 10 12:28:26 0220965500cf powershell[419]: (7.2.1:1:80) [Perftrack_ConsoleStartupStop:PowershellConsoleStartup.WinStop.Informational] PowerShell console is ready for user input
Mar 10 12:28:27 0220965500cf powershell[419]: (7.2.1:B:80) [NamedPipeIPC_ServerListenerError:NamedPipe.Exception.Error] An error has occurred in PowerShell IPC listening thread on process: 419 in AppDomain: None.  Error Message: Operation canceled.

Expected behavior

I have a Nagios install that runs thousands of pwsh scripts per hour.

pwsh -noni -file /usr/lib64/nagios/plugins/script.ps1

I expect this to just work.

Actual behavior

This error appears when I exit the shell, be it from a script or from running pwsh in bash:

[NamedPipeIPC_ServerListenerError:NamedPipe.Exception.Error] An error has occurred in PowerShell IPC listening thread on process: 419 in AppDomain: None.  Error Message: Operation canceled.

Over time, garbage files appear in /tmp

• CoreFxPipe*
• clr-debug*
• dotnet-diag*

I can only assume these are not properly closed and cleaned up because of above error.

And eventually pwsh simply refuses to exit entirely, but only for the nagios user. The shell hangs until it is forcibly shut down by nagios after a 60 second threshold.

Error details

Mar 10 12:28:27 0220965500cf powershell[419]: (7.2.1:B:80) [NamedPipeIPC_ServerListenerError:NamedPipe.Exception.Error] An error has occurred in PowerShell IPC listening thread on process: 419 in AppDomain: None.  Error Message: Operation canceled.

Environment data

PS /> $PSVersionTable

Name                           Value
----                           -----
PSVersion                      7.2.1
PSEdition                      Core
GitCommitId                    7.2.1
OS                             Linux 4.18.0-348.el8.x86_64 #1 SMP Tue Nov 9 06:28:28 EST 2021
Platform                       Unix
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0…}
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1
WSManStackVersion              3.0

Visuals

No response

[mtnielsen]

I suppose I should add this is also the case with the latest 7.3.0-preview.2 from https://packages.microsoft.com/rhel/8/prod/powershell-preview-7.3.0_preview.2-1.rh.x86_64.rpm

[anmenaga]

I can see the An error has occurred in PowerShell IPC listening thread error message on a simple launch and exit of PS v7.3.0-preview.2 on Ubuntu 20:

Mar 29 13:45:52 a-u20-1 powershell[59349]: (7.3.0-preview.2:1:80) [Perftrack_ConsoleStartupStart:PowershellConsoleStartup.WinStart.Informational] PowerShell console is starting up
Mar 29 13:45:52 a-u20-1 powershell[59349]: (7.3.0-preview.2:C:80) [NamedPipeIPC_ServerListenerStarted:NamedPipe.Open.Informational] PowerShell has started an IPC listening thread on process: 59349 in AppDomain: None.
Mar 29 13:45:52 a-u20-1 powershell[59349]: (7.3.0-preview.2:1:80) [Perftrack_ConsoleStartupStop:PowershellConsoleStartup.WinStop.Informational] PowerShell console is ready for user input
Mar 29 13:45:54 a-u20-1 powershell[59349]: (7.3.0-preview.2:C:80) [NamedPipeIPC_ServerListenerError:NamedPipe.Exception.Error] An error has occurred in PowerShell IPC listening thread on process: 59349 in AppDomain: None.  Error Message: Operation canceled.

[AdminValida]

Hi!

We are also using Check_MK/Nagios with active checks to monitor various applications with PS Core scripts. We are also encountering the same error logs.

Regards Richard

[bagajjal]

@AdminValida, temporary workaround to mitigate the logs Modify powershell.config.json to have

"LogLevel": "Critical"

[AdminValida]

@AdminValida, temporary workaround to mitigate the logs Modify powershell.config.json to have

"LogLevel": "Critical"

We are already doing this but this will, for sure, only hide the logs and not solve the problem :-)

Regards

[bagajjal]

@AdminValida - You are correct. This only hides the problem for now. We definitely need a fix.

[jorgeyanesdiez]

I'd like to add that it's also happening to me on Ubuntu 22.04 Server with PowerShell 7.2.5 installed directly from the microsoft repos with apt on the system itself (no containers/podman, no nagios...). Every single time i run and exit powershell I get the same error. It's causing my systemd units which call pwsh to run a script to always fail, and that forces me to run stuff with ExecStart=-xxxx to ignore the error, which is less than ideal.

[srwsolutions]

This is also happening on OpenSuse 15.3 with Powershell 7.2.5 installed. It also appears that the last line of the script is somehow what's triggering this and therefore that last line doesn't execute. I had a simple script for a UPS shutdown sequence where the last line was a Send-MailMessage, and that line didn't successfully execute. After adding a throw away "EXIT" command to the bottom the email message was sent even though the error messages were still placed in the log. As this was a single powershell script with no nesting I can't say whether or not execution would continue if this script had been called by another powershell script and was expecting to have control returned. This script was invoked via pwsh inside a bash script and the bash script did continue, although I didn't check to see if there were error codes returned from pwsh.

[jorgeyanesdiez]

The garbage in /tmp issue is also mentioned in #6324, and I think I have found the cause and solution (see my comment there)

[microsoft-github-policy-service[bot]]

This issue has not had any activity in 6 months, if this is a bug please try to reproduce on the latest version of PowerShell and reopen a new issue and reference this issue if this is still a blocker for you.

[microsoft-github-policy-service[bot]]

This issue has been marked as "No Activity" as there has been no activity for 6 months. It has been closed for housekeeping purposes.

[nixdagbibts]

Can we please reopen this ticket?

I'm facing the same error log entries every time a Powershell command is executed through our Azure Devops Agent

• Debian 12
• Powershell 7.4.1

2024-01-29 04:00:22.858	│ vsts.agent │ info   │ (7.4.1:1:80) [Perftrack_ConsoleStartupStart:PowershellConsoleStartup.WinStart.Informational] PowerShell console is starting up
2024-01-29 04:00:22.966	│ vsts.agent │ info   │ (7.4.1:B:80) [NamedPipeIPC_ServerListenerStarted:NamedPipe.Open.Informational] PowerShell has started an IPC listening thread on process: 3421091 in AppDomain: None.
2024-01-29 04:00:23.062	│ vsts.agent │ info   │ (7.4.1:1:80) [Perftrack_ConsoleStartupStop:PowershellConsoleStartup.WinStop.Informational] PowerShell console is ready for user input
2024-01-29 04:00:23.365	│ vsts.agent │ error  │ (7.4.1:B:80) [NamedPipeIPC_ServerListenerError:NamedPipe.Exception.Error] An error has occurred in PowerShell IPC listening thread on process: 3421091 in AppDomain: None.  Error Message: Operation canceled.