No text from say() or print() within ErrorLogAlarm makes it to the trial/runall log.
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Random Query Generator |
Confirmed
|
High
|
Unassigned |
Bug Description
Though the ErrorLogAlarm reporter works (and greatly so [I've been extending it to make it very powerful for finding previously potentially missed issues]), it does not show any output in the rqg trial logs when using combinations.pl (have not tested runall.pl yet). When issues are found, it correctly exists with STATUS_ALARM, but except for the last two lines:
[...]
# 2013-01-27T11:50:16 Query: ALTER TABLE `table100_
'%s' in 'table%
# 2013-01-27T11:50:18 Query: ALTER TABLE `table100_
lt_int'. Further errors of this kind will be suppressed.
# 2013-01-27T11:50:51 gentest.pl exited with exit status STATUS_ALARM (109)
2013-01-27T11:50:51 [3340] runall.pl will exit with exit status STATUS_ALARM (109)
Nothing is reported. In this case, there are some 'higher-up' reports of impending rqg shutdown:
# 2013-01-27T11:50:46 Child worker process completed successfully.
The error in the log on which ErrorLogAlarm picked up had happened around 47:56.
So, why did the ErrorLogAlarm not pickup on the issue earlier? And why did it not print anything in the log at all? Searching for 'ErrorLogAlarm' only gives things like this:
# 2013-01-27T11:46:46 reporters => ['Shutdown', 'Backtrace', 'QueryTimeout', 'ErrorLog', 'ErrorLogAlarm']
(i.e. non-ErrorLogAlarm text), but actual text from ErrorLogAlarm.pm, for instance:
say("ErrorLogAlarm Reporter will monitor the log file ".$errorlog);
Is not seen at all. One would expect at the very least that to be there at the start somewhere.
So, summary: no text from say() or print() within ErrorLogAlarm makes it to the trial/runall log.
summary: |
- ErrorLogAlarm output missing from trial logs + No text from say() or print() within ErrorLogAlarm makes it to the + trial/runall log. |
Changed in randgen: | |
assignee: | RoelV (roel11) → nobody |
summary: |
- No text from say() or print() within ErrorLogAlarm makes it to the - trial/runall log. + Don't Forget to Buy Ambien Online To Overcome Insomnia |
description: | updated |
description: | updated |
summary: |
- Don't Forget to Buy Ambien Online To Overcome Insomnia + No text from say() or print() within ErrorLogAlarm makes it to the + trial/runall log. |
I see some issue with print() in ErrorLogAlarm reporter, but not as sever as reported in this bug. Please provide steps to repeat if you continue to see the issue as described earlier.
My test was as follows:
1. Created init-file with intentionally misspelled server setting, stored as bad.init:
SET GLOBAL OPTIMIZER_SWITCH = 'index_m3rge=off';
2. Created config file for combinations.pl as follows, stored as temp.cc:
$combinations= Shutdown, Backtrace, ErrorLog, ErrorLogAlarm ' --init- file=$ENV{ 'PWD'}/ bad.init" , conf/optimizer/ optimizer_ no_subquery_ portable. yy", conf/optimizer/ optimizer_ subquery_ semijoin. yy"
[
[
'--seed=random '.
'--threads=1 '.
'--duration=40 '.
'--reporter=
],[
"--mysqld=
''
],[
"--engine=INNODB --views --grammar=
"--engine=MYISAM --views --grammar=
]
];
With this cc-file there will be a total of 4 trials, 2 of which will use the bad init-file and should therefore result in a failure triggered by ErrorLogAlarm.
I used the following command to run combinations.pl:
perl ./combinations.pl --basedir= /path/to/ mysql/install --config=temp.cc --workdir= /path/to/ workdir --no-log --run-all- combinations- once --parallel=2 --force --no-mask
The result I saw was as follows:
As expected, two of the trials resulted in STATUS_OK, and the other two resulted in STATUS_ALARM. The end result from combinations.pl was STATUS_ALARM.
Looking in trial logs, I could see some message from ErrorLogAlarm. In all trial logs, I could see:
# 2013-01-29T08:42:06 ErrorLogAlarm Reporter will monitor the log file /home/johnemb/ mysql/randgen/ workdir- temp/current1_ 1/master- data/.. /log/master. err
In the trial logs for failing tests I could also see:
# 2013-01-29T08:43:02 ALARM from ErrorLogAlarm reporter: Pattern '^Error: |^ERROR| \[ERROR\ ]|allocated at line|missing DBUG_RETURN| ^safe_mutex: |InnoDB: Warning|InnoDB: Error:|InnoDB: Operating system error|Error while setting value' was found in error log. Matching line was:
But, I don't see any such matching line.
At the end of the log I see
runall.pl will exit with exit status STATUS_ALARM (109)
so at least the status indicates that there is a problem with the test.
Looking in the code of ErrorLogAlarm I see the difference between the "Alarm from ErrorLogAlarm reporter" line and the matchine line:
To conclude:
- I am not able to verify that there is a generic problem with all say()/print() calls from the ErrorLogAlarm reporter. It seems that the say() calls actually end up in the output.
- I am able to verify that print() calls, such as printing the matching line, does not seem to work. I am not sure why, but one possible reason may be that for say() log4perl logging is used if available, and for print() log4perl is bypassed. This may affect what end up in the final output.
So, it may be worth while checking if log4perl is installed and used when you run the RQG. If it is not, and you still do not see the print() output, then log4perl is not the issue.
One other possible reason for missing some output could be if hig...