Mlock in Windows

Hi

Does mlock on windows not work anymore?

regards Peter

[Wed Oct 10 20:08:00.461 2018] [14836] WARNING: index 'tVor': mlock() failed: errno 1453 for attributes
[Wed Oct 10 20:08:00.463 2018] [14836] WARNING: index 'tVor': mlock() failed: errno 1453 for strings
[Wed Oct 10 20:08:00.473 2018] [14836] WARNING: index 'tVor': mlock() failed: errno 1453 for dictionary

[

should work as usual. Could you check that you have right to lock memory and your index size could be loaded into memory, ie your box has more free memory than spa \ sps \ spi files of tVor index?

all this files have around 3GB - by 80GB free memory…

regards Peter

ping

So, i have tested with running as a service or stand alone searchd, and have also set permissions in the group policy to allow local services to lock memory - NO LUCK!

Other software on this server like mySQL who also use mlock running perfectly with mlock.

regards Peter

What is your OS version? What Manticore package do you use ?

As I said with my setup mlock on Windows 10 works fine - I see no issues.
To investigate issue further I need reproducible example from you - config \ index files \ search.log after daemon started with --logdebug cli option or maybe you might provide Docker container or VM snapshot that reproduces issue.

Other software on this server like mySQL who also use mlock running perfectly with mlock.

And for MySQL I see they do not have mlock feature implemented on windows that is why you see no warnings there. As according to ticket https://bugs.mysql.com/bug.php?id=37676 “Allow Lock in Memory on Windows” that is still unimplemented feature at MySQL

OS: Windows Server 2016
Manticore 2.7.3 / manticore-2.7.3-180926-d07c4d43-x64-bin.zip

The following config use mlock until a limit from 500 records.
If i set the limit to 1000 or more, mlock fails
spa \ sps \ spi filesize with 500 records = 78KB, free memory 80GB

tnx for helping
Peter

source srcWls
{
sql_db = ******
sql_port = 3308
sql_query = SELECT linkNr,99 AS db,linkDomainNr,linkWls,linkBoost,CASE WHEN RIGHT(linkUrl,4)=’.pdf’ THEN 1 ELSE LENGTH(linkBody) END AS bodyLen,CONVERT(UNCOMPRESS(linkBody) USING ‘latin1’) AS linkBody,linkTitle,linkUrl,linkLng,linkTyp,linkKey,linkDesc FROM tWls LIMIT 500
type = mysql
sql_host = localhost
sql_user = ******
sql_pass = ******
sql_attr_uint = linkLng
sql_attr_uint = linkBoost
sql_attr_uint = linkDomainNr
sql_attr_uint = linkWls
sql_attr_uint = db
sql_attr_uint = bodyLen
sql_attr_uint = linkTyp
sql_query_pre = SET NAMES utf8
}

index tTest
{
source = srcWls
path = d:/sphIndex/sphTest
charset_table = 0…9, A…Z->a…z, _, a…z, U+A8->U+B8, U+B8, U+C0…U+DF->U+E0…U+FF, U+E0…U+FF, U+40
ignore_chars = U+0060
min_word_len = 1
min_prefix_len = 0
min_infix_len = 0
preopen = 1
mlock = 1
}

searchd
{
listen = 3400:mysql41
log = d:/sphIndex/Log/sphTest.log
read_timeout = 5
pid_file = d:/sphIndex/Log/sphTest.pid
workers = thread_pool
net_workers = 1
mysql_version_string = 5.1.17
binlog_path =
}

indexer
{
mem_limit = 32M
write_buffer = 8M
}

I tried mlock setup with config similar to your at my Windows 10 box and see no issues with indexes with Gigabytes in size.

Could you provide complete example? maybe virtual box snapshot there issue pops up easily?

the only thing what i can do is to test the same config on a windows 10 pc …
but anyway, if it runs, fine - then we know the same as now - it not runs on Windows Server 2016.

I mine it must be a problem with the free memory call on the server. So, if nobody can test this on a server, then the problem will never be found.

btw. a database software like Manticore/Sphinx runs mostly on a server system, not on a pc. Just my opinion …

regards Peter

forget it :wink:
I had set mlock to 0 for testing and forget to set back to 1 …
Sorry…

still testing… and now i’m very confused!

same index, same problem
–logdebug - same problem
–logdebugv - same problem
and then
–logdebugvv - it works!

And the stranged thing is, that this index now runs without the --logdebugvv with mlock!
start, stop, reindex - it works…
any idea? :wink:

regards Peter

just for info:
sphinx-2.2.11-release-win64.zip works with the same index with mlock = 1
regards Peter

could you provide search.log for cases with logdebug enabled for either problem exists and problem vanished. As from your description is not clear what happened.

logdebug/v/vv gives the same output with the warnings from mlock - nothing more…

regards Peter

I’d like to see full flow and when issue pop up. Without any logs and reproducible example I can not start investigation.

[Thu Oct 18 12:13:11.214 2018] [4908] listening on all interfaces, port=3400
[Thu Oct 18 12:13:11.214 2018] [4908] DEBUG: 'mva_updates_pool' - nothing specified, using default value 1048576
[Thu Oct 18 12:13:11.219 2018] [4908] DEBUG: Locking the index via file d:/sphIndex/sphTest.spl
[Thu Oct 18 12:13:11.219 2018] [4908] DEBUG: lock d:/sphIndex/sphTest.spl success
[Thu Oct 18 12:13:11.220 2018] [4908] DEBUG: 'binlog_max_log_size' - nothing specified, using default value 268435456
[Thu Oct 18 12:13:11.222 2018] [4908] DEBUG: 'read_unhinted' - nothing specified, using default value 0
[Thu Oct 18 12:13:11.222 2018] [4908] DEBUG: 'read_buffer' - nothing specified, using default value 0
[Thu Oct 18 12:13:11.223 2018] [4908] accepting connections
[Thu Oct 18 12:13:11.226 2018] [19316] prereading 1 indexes
[Thu Oct 18 12:13:11.226 2018] [19316] DEBUG: prereading index 'tTest'
[Thu Oct 18 12:13:11.227 2018] [19316] DEBUG: CSphIndex_VLN::Preread invoked 'tTest'
[Thu Oct 18 12:13:11.229 2018] [19316] WARNING: index 'tTest': mlock() failed: errno 1453 for attributes
[Thu Oct 18 12:13:11.230 2018] [19316] WARNING: index 'tTest': mlock() failed: errno 1453 for dictionary
[Thu Oct 18 12:13:11.231 2018] [19316] DEBUG: Preread successfully finished, hash=232
[Thu Oct 18 12:13:11.232 2018] [19316] DEBUG: prereaded index 'tTest' in 0.006 sec
[Thu Oct 18 12:13:11.234 2018] [19316] prereaded 1 indexes in 0.007 sec
[Thu Oct 18 12:13:28.090 2018] [4908] caught SIGTERM, shutting down
[Thu Oct 18 12:13:28.107 2018] [4908] DEBUG: Unlocking the index (lock d:/sphIndex/sphTest.spl)
[Thu Oct 18 12:13:28.107 2018] [4908] DEBUG: File ID ok, closing lock FD 7, unlinking d:/sphIndex/sphTest.spl
[Thu Oct 18 12:13:28.112 2018] [4908] shutdown complete

[Thu Oct 18 12:13:50.757 2018] [16484] listening on all interfaces, port=3400
[Thu Oct 18 12:13:50.757 2018] [16484] DEBUG: 'mva_updates_pool' - nothing specified, using default value 1048576
[Thu Oct 18 12:13:50.766 2018] [16484] DEBUG: Locking the index via file d:/sphIndex/sphTest.spl
[Thu Oct 18 12:13:50.766 2018] [16484] DEBUG: lock d:/sphIndex/sphTest.spl success
[Thu Oct 18 12:13:50.771 2018] [16484] DEBUG: 'binlog_max_log_size' - nothing specified, using default value 268435456
[Thu Oct 18 12:13:50.776 2018] [16484] DEBUG: 'read_unhinted' - nothing specified, using default value 0
[Thu Oct 18 12:13:50.776 2018] [16484] DEBUG: 'read_buffer' - nothing specified, using default value 0
[Thu Oct 18 12:13:50.779 2018] [16484] accepting connections
[Thu Oct 18 12:13:50.790 2018] [11128] prereading 1 indexes
[Thu Oct 18 12:13:50.791 2018] [11128] DEBUG: prereading index 'tTest'
[Thu Oct 18 12:13:50.792 2018] [18332] DEBUG: 000001A3E1DAD950 wakeup setup, read=528, write=524
[Thu Oct 18 12:13:50.792 2018] [11128] DEBUG: CSphIndex_VLN::Preread invoked 'tTest'
[Thu Oct 18 12:13:50.802 2018] [11128] WARNING: index 'tTest': mlock() failed: errno 1453 for attributes
[Thu Oct 18 12:13:50.804 2018] [11128] WARNING: index 'tTest': mlock() failed: errno 1453 for dictionary
[Thu Oct 18 12:13:50.806 2018] [11128] DEBUG: Preread successfully finished, hash=232
[Thu Oct 18 12:13:50.807 2018] [11128] DEBUG: prereaded index 'tTest' in 0.017 sec
[Thu Oct 18 12:13:50.809 2018] [11128] prereaded 1 indexes in 0.019 sec
[Thu Oct 18 12:13:58.052 2018] [16484] caught SIGTERM, shutting down
[Thu Oct 18 12:13:58.085 2018] [16484] DEBUG: Unlocking the index (lock d:/sphIndex/sphTest.spl)
[Thu Oct 18 12:13:58.085 2018] [16484] DEBUG: File ID ok, closing lock FD 7, unlinking d:/sphIndex/sphTest.spl
[Thu Oct 18 12:13:58.090 2018] [16484] shutdown complete


[Thu Oct 18 12:14:18.156 2018] [9460] listening on all interfaces, port=3400
[Thu Oct 18 12:14:18.157 2018] [9460] DEBUG: 'mva_updates_pool' - nothing specified, using default value 1048576
[Thu Oct 18 12:14:18.161 2018] [9460] DEBUG: WriteLock 00000206292A2C50 wait
[Thu Oct 18 12:14:18.164 2018] [9460] DEBUG: WriteLock 00000206292A2C50
[Thu Oct 18 12:14:18.173 2018] [9460] DEBUG: Locking the index via file d:/sphIndex/sphTest.spl
[Thu Oct 18 12:14:18.175 2018] [9460] DEBUG: lock d:/sphIndex/sphTest.spl success
[Thu Oct 18 12:14:18.177 2018] [9460] DEBUG: Unlock 00000206292A2C50
[Thu Oct 18 12:14:18.180 2018] [9460] DEBUG: 'binlog_max_log_size' - nothing specified, using default value 268435456
[Thu Oct 18 12:14:18.183 2018] [9460] DEBUG: 'read_unhinted' - nothing specified, using default value 0
[Thu Oct 18 12:14:18.184 2018] [9460] DEBUG: 'read_buffer' - nothing specified, using default value 0
[Thu Oct 18 12:14:18.186 2018] [9460] DEBUG: ReadLock 00000206292A2C50
[Thu Oct 18 12:14:18.187 2018] [9460] DEBUG: Unlock 00000206292A2C50
[Thu Oct 18 12:14:18.190 2018] [9460] accepting connections
[Thu Oct 18 12:14:18.198 2018] [16180] prereading 1 indexes
[Thu Oct 18 12:14:18.198 2018] [16180] DEBUG: ReadLock 00000206292A2C50
[Thu Oct 18 12:14:18.199 2018] [9380] DEBUG: 00000206292B09D0 wakeup setup, read=528, write=524
[Thu Oct 18 12:14:18.200 2018] [16180] DEBUG: prereading index 'tTest'
[Thu Oct 18 12:14:18.202 2018] [16180] DEBUG: CSphIndex_VLN::Preread invoked 'tTest'
[Thu Oct 18 12:14:18.206 2018] [16180] WARNING: index 'tTest': mlock() failed: errno 1453 for attributes
[Thu Oct 18 12:14:18.209 2018] [16180] WARNING: index 'tTest': mlock() failed: errno 1453 for dictionary
[Thu Oct 18 12:14:18.209 2018] [16180] DEBUG: Preread successfully finished, hash=232
[Thu Oct 18 12:14:18.210 2018] [16180] DEBUG: prereaded index 'tTest' in 0.011 sec
[Thu Oct 18 12:14:18.211 2018] [16180] DEBUG: Unlock 00000206292A2C50
[Thu Oct 18 12:14:18.213 2018] [16180] prereaded 1 indexes in 0.015 sec
[Thu Oct 18 12:14:23.244 2018] [5136] DEBUG: ReadLock 00000206292A2C50
[Thu Oct 18 12:14:23.244 2018] [5136] DEBUG: Unlock 00000206292A2C50
[Thu Oct 18 12:14:28.295 2018] [5136] DEBUG: ReadLock 00000206292A2C50
[Thu Oct 18 12:14:28.295 2018] [5136] DEBUG: Unlock 00000206292A2C50
[Thu Oct 18 12:14:33.346 2018] [5136] DEBUG: ReadLock 00000206292A2C50
[Thu Oct 18 12:14:33.346 2018] [5136] DEBUG: Unlock 00000206292A2C50
[Thu Oct 18 12:14:37.582 2018] [9460] caught SIGTERM, shutting down
[Thu Oct 18 12:14:37.636 2018] [9460] DEBUG: ReadLock 00000206292A2C50
[Thu Oct 18 12:14:37.636 2018] [9460] DEBUG: Unlock 00000206292A2C50
[Thu Oct 18 12:14:37.638 2018] [9460] DEBUG: ReadLock 00000206292A2C50
[Thu Oct 18 12:14:37.640 2018] [9460] DEBUG: Unlocking the index (lock d:/sphIndex/sphTest.spl)
[Thu Oct 18 12:14:37.641 2018] [9460] DEBUG: File ID ok, closing lock FD 7, unlinking d:/sphIndex/sphTest.spl
[Thu Oct 18 12:14:37.643 2018] [9460] DEBUG: Unlock 00000206292A2C50
[Thu Oct 18 12:14:37.648 2018] [9460] shutdown complete

We just reproduced this issue and I created ticket at Github github#125 You might subscribe there to be informed on progress of fixing this issue.

regards Stan

many thanks
regards Peter