mokraemer, would you be able temporarily enable general log on the instance where you are getting the issue? This way we'll know what kind of concurrency, if any, we are dealing with. General log can affect performance, but I assume it's not critical for you at least at nights, if you can afford massive table maintenance.
In fact, you can add it to your nightly job, enabling it right before the check/optimize/analyze, and disabling it afterwards.
When the corruption happens next time, we'll match its time with the general log and will see what else was happening with the same table.
Also, Alessandro wrote in MDEV-8572 (which I'm closing as a duplicate of this report):
Hi,
we migrated all db server form mysql 5.1 to mariadb 10.0.19 and now we found randomly after optimize of all dbs weekly with command
mysqlcheck --auto-repair --flush -Ao
we find a corrupted myisam tables (before optimize we are sure that tables are ok because no log is present in optimize log that warn about problem on table) and a relative .tmm file.
We have to delete .tmm file and repair the table because if mysqlcheck pass skip this tables
Thank you very much
Like reported from Marc , we see a lock problem with the same tables that we found crashed and we try to solve it settings lock_wait_timeout = 120 instead 31536000 because we found the tables in race from try to lock from optimize jobs forever and we have to kill the process manually.
Thank you very much
@Elena thanks for your comment.
I changed my cron to enable the log just before the execution (why this didn't came into my mind...)
Since I haven't yet found a way to reproduce this reliable, it can take some time until I can report on this.
@Fustini: did you enable the general log during optimize as well?
For me, I didn't have any optimize issues so far. The appeared not very regular at my server, so maybe this is accidental or enabling the lock changes the behavior, which would be bad to track it down.
If not done so far, please enable, so we can track down this issue.
Hi, I'm in holiday at moment.
When return I ask to my collegaue if possibel tio do that because the db server are in production with shared hosting and create tons of logs.
if you enable the task just before mysqloptimize & disable afterwards, this should not give too much impact
HI,
I have news about the test on Mariadb 10.0.19 .. this is the command list
MariaDB [(none)]> SET GLOBAL log_output=FILE;
Query OK, 0 rows affected (0.00 sec)
MariaDB [(none)]> SET GLOBAL general_log_file='/var/lib/mysql/mysql-general.log';
Query OK, 0 rows affected (0.00 sec)
MariaDB [(none)]> SET GLOBAL general_log = ON;
Query OK, 0 rows affected (0.03 sec)
MariaDB [(none)]> optimize table xxxxxxxxx.rkt27_k2_items;
ERROR 2013 (HY000): Lost connection to MySQL server during query
MariaDB [(none)]> Bye
and this is the file list of after crash
[root@xxxxxxxxx]# ls -latr rkt27_k2_items*
rw-rw--- 1 mysql mysql 18224 18 giu 12:55 rkt27_k2_items.frm
rw-rw--- 1 mysql mysql 84025984 26 ago 08:32 rkt27_k2_items.MYD
rw-rw--- 1 mysql mysql 74606592 26 ago 08:36 rkt27_k2_items.MYI
rw-rw--- 1 mysql mysql 74902528 26 ago 09:24 rkt27_k2_items.TMM
In the general log nothing is present after command
optimize table xxxxxxxxx.rkt27_k2_items;
Thank you
Hi,
this is the strucure of table rkt27_k2_items.
Ask to me if you need any other data
Table: rkt27_k2_items
Create Table: CREATE TABLE `rkt27_k2_items` (
`id` int(11) NOT NULL AUTO_INCREMENT,
`title` varchar(255) NOT NULL,
`alias` varchar(255) DEFAULT NULL,
`catid` int(11) NOT NULL,
`published` smallint(6) NOT NULL DEFAULT '0',
`introtext` mediumtext NOT NULL,
`fulltext` mediumtext NOT NULL,
`video` text,
`gallery` varchar(255) DEFAULT NULL,
`extra_fields` text CHARACTER SET utf8 COLLATE utf8_unicode_ci,
`extra_fields_search` text NOT NULL,
`created` datetime NOT NULL,
`created_by` int(11) NOT NULL DEFAULT '0',
`created_by_alias` varchar(255) NOT NULL,
`checked_out` int(10) unsigned NOT NULL,
`checked_out_time` datetime NOT NULL,
`modified` datetime NOT NULL,
`modified_by` int(11) NOT NULL DEFAULT '0',
`publish_up` datetime NOT NULL,
`publish_down` datetime NOT NULL,
`trash` smallint(6) NOT NULL DEFAULT '0',
`access` int(11) NOT NULL DEFAULT '0',
`ordering` int(11) NOT NULL DEFAULT '0',
`featured` smallint(6) NOT NULL DEFAULT '0',
`featured_ordering` int(11) NOT NULL DEFAULT '0',
`image_caption` text NOT NULL,
`image_credits` varchar(255) NOT NULL,
`video_caption` text NOT NULL,
`video_credits` varchar(255) NOT NULL,
`hits` int(10) unsigned NOT NULL,
`params` text NOT NULL,
`metadesc` text NOT NULL,
`metadata` text NOT NULL,
`metakey` text NOT NULL,
`plugins` text NOT NULL,
`language` char(7) NOT NULL,
PRIMARY KEY (`id`),
KEY `item` (`published`,`publish_up`,`publish_down`,`trash`,`access`),
KEY `catid` (`catid`),
KEY `created_by` (`created_by`),
KEY `ordering` (`ordering`),
KEY `featured` (`featured`),
KEY `featured_ordering` (`featured_ordering`),
KEY `hits` (`hits`),
KEY `created` (`created`),
KEY `language` (`language`),
FULLTEXT KEY `search` (`title`,`introtext`,`fulltext`,`extra_fields_search`,`image_caption`,`image_credits`,`video_caption`,`video_credits`,`metadesc`,`metakey`),
FULLTEXT KEY `title` (`title`)
) ENGINE=MyISAM AUTO_INCREMENT=19734 DEFAULT CHARSET=utf8
so the problem is, if the connection dies during the optimize command, the optimization is not finished - not sure if this is what is expected. I think the server should finish any administrative command, such as optimize, analyze, ... and not break during this execution.
But even if it breaks, no stale file should be left.
@Fustini: thanks - on my machine it never happens after enabling the log. Maybe the connection timeout is reset so currently I don't see this. But I think the this is severe.
Had the same issue again.
@Elena: in general log is nothing remarkable. No query running in between - just an excerpt:
150902 1:12:27 97250 Query CHECK TABLE `tblversions`
[...]
97251 Connect root@localhost as anonymous on
97251 Init DB db
97251 Query SHOW /!50002 FULL/ TABLES
97251 Query OPTIMIZE TABLE `t1`
150902 1:12:28 97251 Query OPTIMIZE TABLE `t2`
from mysql-error-log
150902 1:12:33 [ERROR] mysqld: Table './db/msgData' is marked as crashed and last (automatic?) repair failed
=> an .TMM file was present at this time.
Alessandro,
So, in your last example, when optimize finishes with Lost connection to MySQL server during query, the server does not really crash? Did you check the error log for any signs of server restart at this moment?
How long did it take between you issued the optimize command and it aborted with Lost connection?
Was the table locked in another connection?
Could you please attach your my.cnf file(s)?
mokraemer,
Same question to you regarding any signs of server restart in the error log.
Thanks.
Hi Elena,
the server crash immediatly after optimize command and becomes running after 5/6 minutes.I set the zabbix's check alert on mysql on ten minutes then some times this situation was not reported to me, after I reset the alert on 4 minutes and last week I saw 11 servers on 103 to crash on optimize phase.
In the error log I do not found nothing and in the log process I see "normal" operation on recover Innodb log after crash.
Sometimes, on the same tables that more frequently crash servers on this situatiuon, on Monday (after many hours when I Start optimize) the users report problem on access the tables. If I use Show full process list I found a " tryingto get lock on table" that runs from many hours and continue to run forever (locked thread ?).
In this case I kill the optimize manually to bypass the problem and the tables becomes readable / writable again (and not tmm file is present).
The table that trigger this kind of crash seem to be a MYisam table (no Innodb at the moment) heavy used at moment on other thread when optimize try to do this operation
Tomorrow attach my cnf file.
Thanks
If the server crashes, there must be at least something in the error log to indicate it – a message that the server received a terminating signal, an attempt to write a stack trace, etc. Can you provide it? (Or better still, please attach the whole error log).
If there really nothing at all, just server running normally and suddenly the next line shows that it's being started again, it looks like something kills it from outside. Did you check your system logs for OOM killer activity? Do you have any memory monitoring on the machines to see if it spikes before the server crashes?
Hi Elena,
no OOM killer activity because I do not found any logs for this process / day / hour.
We have only memory logs for the last 3 days .... than no data for this.
I found this in Mariadb error log (I start the optimize 15- 08- 26 at 9:24:25 ) :
......
150825 11:19:48 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
150825 11:19:50 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
150825 11:19:53 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
150825 11:19:55 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
150825 11:19:58 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
150825 11:19:59 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
150825 11:20:02 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
150825 11:20:04 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
150825 11:35:12 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
150825 11:35:27 [ERROR] mysqld: Table './xxxx_xxxxx/rkt27_k2_items' is marked as crashed and last (automatic?) repair failed
(I start the optimize here)
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 9:24:25 [ERROR] mysqld: Incorrect key file for table './xxxx_xxxxx/rkt27_k2_items.MYI'; try to repair it
150826 09:24:26 mysqld_safe Number of processes running now: 0
150826 09:24:26 mysqld_safe mysqld restarted
/usr/sbin/mysqld: /usr/local/lib/libz.so.1: no version information available (required by /usr/sbin/mysqld)
150826 9:24:26 [Note] /usr/sbin/mysqld (mysqld 10.0.19-MariaDB-log) starting as process 90342 ...
150826 9:24:26 [Note] InnoDB: Using mutexes to ref count buffer pool pages
150826 9:24:26 [Note] InnoDB: The InnoDB memory heap is disabled
150826 9:24:26 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
150826 9:24:26 [Note] InnoDB: Memory barrier is not used
150826 9:24:26 [Note] InnoDB: Compressed tables use zlib 1.2.3
150826 9:24:26 [Note] InnoDB: Using Linux native AIO
150826 9:24:26 [Note] InnoDB: Using CPU crc32 instructions
150826 9:24:26 [Note] InnoDB: Initializing buffer pool, size = 128.0M
150826 9:24:26 [Note] InnoDB: Completed initialization of buffer pool
150826 9:24:26 [Note] InnoDB: Highest supported file format is Barracuda.
150826 9:24:26 [Note] InnoDB: The log sequence numbers 487031020215 and 487031020215 in ibdata files do not match the log sequence number 594331385734 in the ib_logfiles!
150826 9:24:26 [Note] InnoDB: Database was not shutdown normally!
150826 9:24:26 [Note] InnoDB: Starting crash recovery.
150826 9:24:26 [Note] InnoDB: Reading tablespace information from the .ibd files...
150826 9:35:02 [Note] InnoDB: Restoring possible half-written data pages
150826 9:35:02 [Note] InnoDB: from the doublewrite buffer...
150826 9:35:04 [Note] InnoDB: 128 rollback segment(s) are active.
150826 9:35:04 [Note] InnoDB: Waiting for purge to start
150826 9:35:04 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.23-72.1 started; log sequence number 594331385734
150826 9:35:04 [Note] Plugin 'FEEDBACK' is disabled.
150826 9:35:04 [Note] Server socket created on IP: '::'.
150826 9:35:05 [Note] Event Scheduler: Loaded 0 events
150826 9:35:05 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.0.19-MariaDB-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
150826 9:35:06 [ERROR] mysqld: Table './xxxxxxxxxxx/esa70_k2_items' is marked as crashed and should be repaired
.....
Thanks a lot
Could you please paste (or upload to ftp.askmonty.org/private) the output of
SHOW CREATE TABLE rkt27_k2_items;
|
SHOW INDEX IN rkt27_k2_items;
|
SHOW TABLE STATUS LIKE 'rkt27_k2_items';
|
The request for my.cnf is also still valid.
It's weird that the process disappears without any sign of what happened to it either in its error log, or in system logs...
mokraemer,
Is it the same for you? The process also disappears silently?
Hi Elena,
I copied in ftp data_table_mariadb.txt all the data
Thank you
Hi,
sorry for the late reply (was on holiday).
In my case, the process does NOT disappear. The only thing I can see as related might be the log rotation. I use the following script:
/var/log/mysqld/*.log
|
rotate 5
|
weekly
|
missingok
|
notifempty
|
compress
|
create 644 mysql mysql
|
sharedscripts
|
prerotate
|
mysqladmin flush-logs
|
endscript
|
postrotate
|
mysqladmin flush-logs
|
endscript
|
but this did not cause a process reload, which I'm monitoring & checked the logs
Alessandro, mokraemer, thanks, it seems I am now able to reproduce the problem with a concurrent test.
svoj (or whoever ends up fixing it),
below is the RQG test. Use lp:~elenst/randgen/mariadb-patches to run it.
|
RQG grammar mdev8571.yy |
query_init:
|
CREATE TABLE IF NOT EXISTS t1 (id INT NOT NULL AUTO_INCREMENT PRIMARY KEY) ENGINE=MyISAM; CREATE TABLE IF NOT EXISTS t2 LIKE t1;
|
|
|
query:
|
REPLACE INTO my_table () VALUES (),();
|
|
|
thread1:
|
OPTIMIZE TABLE my_table;
|
|
|
my_table:
|
t1 | t2;
|
|
RQG command line |
perl ./runall-new.pl --grammar=mdev8571.yy --skip-gendata --threads=2 --queries=100M --duration=120 --mysqld=--wait-timeout=10 --basedir=<10.0 basedir> --vardir=<your vardir>
|
When the problem is hit, the output looks like this:
# 2015-09-17T03:24:39 [24975] Caching schema metadata for dbi:mysql:host=127.0.0.1:port=18570:user=rqg:database=test
|
# 2015-09-17T03:24:40 [24975] Starting 2 processes, 100000000 queries each, duration 120 seconds.
|
# 2015-09-17T03:24:40 [24975] GenTest::ErrorFilter(25178) started
|
# 2015-09-17T03:24:40 [25179] Started periodic reporting process...
|
# 2015-09-17T03:24:53 [25182] Query: REPLACE INTO t1 () VALUES (),() failed: 144 Table './test/t1' is marked as crashed and last (automatic?) repair failed
|
# 2015-09-17T03:24:53 [25182] Query: REPLACE INTO t1 () VALUES (),() failed: 144 Table './test/t1' is marked as crashed and last (automatic?) repair failed
|
...
|
It should happen in ~10 seconds after 'Started reporting process' (or in wait_timeout seconds, if one changes the value provided on the command line).
The printed error is not the problem in itself, it's just a side effect (see MDEV-8475). The real problem is that at some point a TMM file does not get removed.
There is no visible problem with OPTIMIZE, so I'm not sure what makes it bypass the file removal, it is to be investigated.
I could not reproduce it on 5.5 (which explains why reporters reported a regression), and it cannot be seen with this test on 10.1 because MDEV-8475 has been fixed there, and the error on REPLACE does not happen, even though the underlying issue might still exist. All in all, I suggest to investigate it on 10.0 and then check if other versions are affected.
wow finally we got a test-case - thanks Elena!
elenst, I spent half of the day attempting to run it with --basedir=. 
serg, please review fix for this bug.
ok to push, obviously