[Bug 21572] KFSensor 4.x/5.x: 'kfsnserv.exe' service fails to reliably stop/start/restart
WineHQ Bugzilla
wine-bugs at winehq.org
Fri Nov 12 04:05:24 CST 2021
https://bugs.winehq.org/show_bug.cgi?id=21572
Anastasius Focht <focht at gmx.net> changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|UNCONFIRMED |RESOLVED
Keywords|Abandoned? |
Resolution|--- |FIXED
Summary|KFSensor 4.5.0 Professional |KFSensor 4.x/5.x:
|Trial: Trouble starting and |'kfsnserv.exe' service
|stopping the service |fails to reliably
| |stop/start/restart
URL|http://www.keyfocus.net/kfs |https://web.archive.org/web
|ensor/download/kfsens40.exe |/20211112083705/http://www.
| |keyfocus.net/kfsensor/downl
| |oad/kfsens40.exe
CC| |focht at gmx.net
--- Comment #7 from Anastasius Focht <focht at gmx.net> ---
Hello folks,
--- quote ---
Screenshot showing everything is fine
--- quote ---
your screenshot shows an empty treeview on the left-hand side ('localhost'
node). Just because the main UI is shown doesn't mean things are fixed.
There were different issues mixed in here. The packet/npptools modules were
separately handled. This one is about the 'kfsnserv.exe' service not properly
running after stop/start (restart) sequences.
Did you start/stop/(re)start the system service via UI and check what's
happening?
--- snip ---
$ pwd
/home/focht/.wine/drive_c/Program Files (x86)/KeyFocus/KFSensor/bin
$ WINEDEBUG=+loaddll,+process,+service wine ./kfsensmonitor.exe
...
003c:trace:service:scmdatabase_load_services Loading service L"KeyFocusSensor"
003c:trace:service:load_service_config Image path = L"C:\\Program
Files (x86)\\KeyFocus\\KFSensor\\bin\\kfsnserv.exe"
003c:trace:service:load_service_config Group = (null)
003c:trace:service:load_service_config Service account name = L"LocalSystem"
003c:trace:service:load_service_config Display name = L"KFSensor"
003c:trace:service:load_service_config Service dependencies : (none)
003c:trace:service:load_service_config Group dependencies : (none)
003c:trace:service:scmdatabase_load_services Loading service L"KFMond"
003c:trace:service:load_service_config Image path = L"C:\\Program
Files (x86)\\KeyFocus\\KFSensor\\bin\\kfmond.exe"
003c:trace:service:load_service_config Group = (null)
003c:trace:service:load_service_config Service account name = L"LocalSystem"
003c:trace:service:load_service_config Display name = L"KFSensor
Monitor Service"
003c:trace:service:load_service_config Service dependencies : (none)
003c:trace:service:load_service_config Group dependencies : (none)
...
--- snip ---
There are log files in 'c:\\kfsensor\\logs\\system_<datestamp>.log' about
service status/failures.
First, you need 'cap_net_raw+epi' on Wine's 32-bit preloader otherwise the
service behaves badly.
--- snip ---
...
[2021/11/12 10:38:20.593 5 +0100] Service starting {INFO} <5.6.0>
[2021/11/12 10:38:20.610 5 +0100] Config {INFO} <SysLog: Enabled:False
Format:STD Server::514>
[2021/11/12 10:38:20.629 5 +0100] Cannot listen to network interface 'wlp4s0.
', interface is not IP based {WARNING}
<\Device\NPF_{00000003-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.630 5 +0100] Cannot listen to network interface
'virbr0-nic. ', interface is not IP based {WARNING}
<\Device\NPF_{00000005-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.638 5 +0100] Error opening network interface 'enp5s0'
{ERROR} <enp5s0: You don't have permission to capture on that device (socket:
Operation not permitted), \Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.639 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.645 5 +0100] Error opening network interface 'enp5s0'
{ERROR} <enp5s0: You don't have permission to capture on that device (socket:
Operation not permitted), \Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.645 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.651 5 +0100] Error opening network interface 'lo' {ERROR}
<lo: You don't have permission to capture on that device (socket: Operation not
permitted), \Device\NPF_{00000001-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.651 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000001-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.657 5 +0100] Error opening network interface 'enp5s0'
{ERROR} <enp5s0: You don't have permission to capture on that device (socket:
Operation not permitted), \Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.657 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.664 5 +0100] Error opening network interface 'lo' {ERROR}
<lo: You don't have permission to capture on that device (socket: Operation not
permitted), \Device\NPF_{00000001-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.664 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000001-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.670 5 +0100] Error opening network interface 'virbr0'
{ERROR} <virbr0: You don't have permission to capture on that device (socket:
Operation not permitted), \Device\NPF_{00000004-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.670 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000004-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.676 5 +0100] Error opening network interface 'enp5s0'
{ERROR} <enp5s0: You don't have permission to capture on that device (socket:
Operation not permitted), \Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.676 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.678 5 +0100] ERROR: Bind on port {ERROR} <TCP Any:1>
[2021/11/12 10:38:20.679 5 +0100] ERROR: Bind on port {ERROR} <TCP Any:7>
...
[2021/11/12 10:38:20.695 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.697 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:7>
[2021/11/12 10:38:20.699 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:13>
[2021/11/12 10:38:20.699 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:17>
[2021/11/12 10:38:20.699 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:19>
[2021/11/12 10:38:20.699 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:67>
[2021/11/12 10:38:20.699 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:137>
[2021/11/12 10:38:20.700 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:138>
[2021/11/12 10:38:20.700 5 +0100] Service started {NOTICE} <5.6.0>
[2021/11/12 10:38:20.702 5 +0100] Error opening network interface 'lo' {ERROR}
<lo: You don't have permission to capture on that device (socket: Operation not
permitted), \Device\NPF_{00000001-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.702 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000001-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.708 5 +0100] Error opening network interface 'virbr0'
{ERROR} <virbr0: You don't have permission to capture on that device (socket:
Operation not permitted), \Device\NPF_{00000004-0000-0000-0000-4E6574446576}>
[2021/11/12 10:38:20.708 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000004-0000-0000-0000-4E6574446576}>
...
<repeats endlessly, filling logs very quickly>
--- snip ---
Because of that, SCM requests to the service to stop take ~40 secs to be
fulfilled:
--- snip ---
[2021/11/12 10:39:49.421 5 +0100] Service stopping {NOTICE}
...
[2021/11/12 10:40:31.718 5 +0100] Error opening network interface 'virbr0'
{ERROR} <virbr0: You don't have permission to capture on that device (socket:
Operation not permitted), \Device\NPF_{00000004-0000-0000-0000-4E6574446576}>
[2021/11/12 10:40:31.718 5 +0100] Network capture shutting down {NOTICE}
<\Device\NPF_{00000004-0000-0000-0000-4E6574446576}>
[2021/11/12 10:40:31.724 5 +0100] Service stopped {NOTICE} <5.6.0>
--- snip ---
If you try stop the service in between via UI you will get "an error occurred
controlling the system service".
With 'cap_net_raw+epi' the service is obviously more responsive - because it
can open network interfaces for capture.
--- snip ---
$ sudo setcap cap_net_raw+eip $(which wine-preloader)
--- snip ---
--- snip ---
[2021/11/12 10:44:38.682 5 +0100] Service starting {INFO} <5.6.0>
[2021/11/12 10:44:38.691 5 +0100] Config {INFO} <SysLog: Enabled:False
Format:STD Server::514>
[2021/11/12 10:44:38.705 5 +0100] Cannot listen to network interface 'wlp4s0.
', interface is not IP based {WARNING}
<\Device\NPF_{00000003-0000-0000-0000-4E6574446576}>
[2021/11/12 10:44:38.706 5 +0100] Cannot listen to network interface
'virbr0-nic. ', interface is not IP based {WARNING}
<\Device\NPF_{00000005-0000-0000-0000-4E6574446576}>
[2021/11/12 10:44:38.725 5 +0100] Monitoring network interface 'enp5s0' {INFO}
<\Device\NPF_{00000002-0000-0000-0000-4E6574446576}>
[2021/11/12 10:44:38.743 5 +0100] Monitoring network interface 'lo' {INFO}
<\Device\NPF_{00000001-0000-0000-0000-4E6574446576}>
[2021/11/12 10:44:38.761 5 +0100] Monitoring network interface 'virbr0' {INFO}
<\Device\NPF_{00000004-0000-0000-0000-4E6574446576}>
[2021/11/12 10:44:38.769 5 +0100] ERROR: Bind on port {ERROR} <TCP Any:1>
[2021/11/12 10:44:38.769 5 +0100] ERROR: Bind on port {ERROR} <TCP Any:7>
...
[2021/11/12 10:44:38.792 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:137>
[2021/11/12 10:44:38.792 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:138>
[2021/11/12 10:44:38.793 5 +0100] Service started {NOTICE} <5.6.0>
--- snip ---
Stopping - still takes considerable time but less than before:
--- snip ---
[2021/11/12 10:46:06.980 5 +0100] Service stopping {NOTICE}
[2021/11/12 10:46:26.160 5 +0100] Service stopped {NOTICE} <5.6.0>
--- snip ---
'restart' via UI:
--- snip ---
[2021/11/12 10:53:08.969 5 +0100] Service Restart request {NOTICE}
[2021/11/12 10:53:08.969 5 +0100] Service stopping {NOTICE}
[2021/11/12 10:53:26.433 5 +0100] Service stopped {NOTICE} <5.6.0>
[2021/11/12 10:53:26.627 5 +0100] Loaded 1 Visitor Rules {INFO}
[2021/11/12 10:53:26.638 5 +0100] Loaded 36 signatures, time: 2021-04-19
03:06:58:000 {NOTICE} <C:\kfsensor\conf\kfsigs.xml>
[2021/11/12 10:53:26.641 5 +0100] Service starting {INFO} <5.6.0>
...
[2021/11/12 10:53:26.753 5 +0100] ERROR: Bind on port {ERROR} <UDP Any:138>
[2021/11/12 10:53:26.754 5 +0100] Service started {NOTICE} <5.6.0>
--- snip ---
BTW the current 'kfsens40.exe' download is KFSensor v5.6.0. The vendor decided
to recycle the same binary name 'kfsens40.exe' for different versions for
whatever stupid reasons. No prior archive.org snapshots exist from the original
vendor site. There might be alternate mirrors with older versions which have
archive.org snapshots though.
https://web.archive.org/web/20211112083705/http://www.keyfocus.net/kfsensor/download/kfsens40.exe
$ sha1sum kfsens40.exe
476ab6937c962395c8149dc05639b57d67a099b1 kfsens40.exe
$ du -sh kfsens40.exe
3.8M kfsens40.exe
$ wine --version
wine-6.21-182-g3dbce69fd4c
Regards
--
Do not reply to this email, post in Bugzilla using the
above URL to reply.
You are receiving this mail because:
You are watching all bug changes.
More information about the wine-bugs
mailing list