Weird results of the test
wpoely86 opened this issue · 1 comments
wpoely86 commented
If I run ./runtest.py -d -E 42 -V 2.0.0 and ./runtest.py -d -E 43 -V 2.0.0 both give a positive result. However, If I do both:
$ ./runtest.py -d -E 42,43 -V 2.0.0
2016-01-06 10:30:30,562 DEBUG runtest.ExtOption MainThread changed loglevel to DEBUG, previous state: (runtest.SimpleOptionParser, NOTSET), (runtest.ExtOptionGroup, NOTSET), (runtest, NOTSET), (runtest.vsc.utils.missing, NOTSET), (runtest.ExtOption, NOTSET), (runtest.RUNTEST, NOTSET)
2016-01-06 10:30:30,562 DEBUG runtest.RUNTEST MainThread parseoptions: options from environment []
2016-01-06 10:30:30,562 DEBUG runtest.RUNTEST MainThread parseoptions: options from commandline ['-d', '-E', '42,43', '-V', '2.0.0']
2016-01-06 10:30:30,562 DEBUG runtest.RUNTEST MainThread Found options {'info': False, 'logstash_version': '2.0.0', 'help': None, 'quiet': False, 'configfiles': None, 'debug': True, 'entries': ['42', '43'], 'ignoreconfigfiles': None, 'last': False, 'first': False} args []
2016-01-06 10:30:30,562 DEBUG runtest.RUNTEST MainThread Initialise case sensitive configparser
2016-01-06 10:30:30,562 DEBUG runtest.RUNTEST MainThread parseconfigfiles: configfiles initially set []
2016-01-06 10:30:30,562 DEBUG runtest.RUNTEST MainThread parseconfigfiles: configfiles set through commandline None
2016-01-06 10:30:30,562 DEBUG runtest.RUNTEST MainThread parseconfigfiles: ignoreconfigfiles set through commandline None
2016-01-06 10:30:30,562 DEBUG runtest.RUNTEST MainThread parseconfigfiles: following files were parsed []
2016-01-06 10:30:30,563 DEBUG runtest.RUNTEST MainThread parseconfigfiles: following files were NOT parsed []
2016-01-06 10:30:30,563 DEBUG runtest.RUNTEST MainThread parseconfigfiles: sections (w/o DEFAULT) []
2016-01-06 10:30:30,563 DEBUG runtest.RUNTEST MainThread parseconfigfiles: no section MAIN
2016-01-06 10:30:30,563 DEBUG runtest.RUNTEST MainThread parseconfigfiles: no section ('NO', 'SECTION')
2016-01-06 10:30:30,563 DEBUG runtest.RUNTEST MainThread parseconfigfiles: going to parse options through cmdline []
2016-01-06 10:30:30,563 DEBUG runtest.SimpleOptionParser MainThread Not processing environment for options
2016-01-06 10:30:30,563 DEBUG runtest.RUNTEST MainThread parseconfigfiles: options from configfile []
2016-01-06 10:30:30,563 DEBUG runtest.RUNTEST MainThread parseconfigfiles: parsed values from configfiles: {}
2016-01-06 10:30:30,565 DEBUG runtest.RUNTEST MainThread Data found in datafile data/00_first
2016-01-06 10:30:30,565 DEBUG runtest.RUNTEST MainThread Data found in datafile data/ceph
2016-01-06 10:30:30,565 DEBUG runtest.RUNTEST MainThread Data found in datafile data/general_syslog
2016-01-06 10:30:30,566 DEBUG runtest.RUNTEST MainThread Data found in datafile data/jube
2016-01-06 10:30:30,566 DEBUG runtest.RUNTEST MainThread Data found in datafile data/modulecmd
2016-01-06 10:30:30,566 DEBUG runtest.RUNTEST MainThread Data found in datafile data/nfs
2016-01-06 10:30:30,566 DEBUG runtest.RUNTEST MainThread Data found in datafile data/opennebula
2016-01-06 10:30:30,566 DEBUG runtest.RUNTEST MainThread Data found in datafile data/quattor
2016-01-06 10:30:30,567 DEBUG runtest.RUNTEST MainThread Data found in datafile data/snoopy
2016-01-06 10:30:30,567 DEBUG runtest.RUNTEST MainThread Data found in datafile data/ssh
2016-01-06 10:30:30,567 DEBUG runtest.RUNTEST MainThread Data found in datafile data/su
2016-01-06 10:30:30,567 DEBUG runtest.RUNTEST MainThread Data found in datafile data/zz_last
2016-01-06 10:30:30,568 DEBUG runtest.RUNTEST MainThread Data found in datafile data/zzz_last
2016-01-06 10:30:30,570 DEBUG runtest.RunAsyncLoop MainThread _popen_named_args {'executable': '/bin/bash', 'shell': True, 'stdout': -1, 'close_fds': True, 'stdin': -1, 'stderr': -2}
2016-01-06 10:30:30,571 DEBUG runtest.RunAsyncLoop MainThread _init_input: process stdin closed
2016-01-06 10:30:39,448 DEBUG runtest.RunAsyncLoop MainThread _wait_for_process: loop stopped after 10 iterations (ec 0 loop_continue True)
2016-01-06 10:30:39,448 DEBUG runtest.RunAsyncLoop MainThread _post_exitcode: success cmd ['logstash', 'agent', '-p', '/home/ward/Documents/codes/logstash-patterns', '-f', '/home/ward/Documents/codes/logstash-patterns/tests/logstash_2.0.0.conf']: output {:timestamp=>"2016-01-06T10:30:38.017000+0100", :message=>"bytes2human plugin is using the 'milestone' method to declare the version of the plugin this method is deprecated in favor of declaring the version inside the gemspec.", :level=>:warn}
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:81 warning: already initialized constant SI
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:83 warning: already initialized constant BINARY
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:85 warning: already initialized constant PREFIXES
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:221 warning: already initialized constant Floppy
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:223 warning: already initialized constant CD
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:225 warning: already initialized constant DVD_5
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:227 warning: already initialized constant DVD
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:229 warning: already initialized constant DVD_9
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:231 warning: already initialized constant DVD_10
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:233 warning: already initialized constant DVD_14
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:235 warning: already initialized constant DVD_18
/home/ward/Documents/codes/logstash-patterns/logstash/filters/bytes2human.rb:237 warning: already initialized constant ZIP
{:timestamp=>"2016-01-06T10:30:38.034000+0100", :message=>"bytes2human plugin doesn't have a version. This plugin isn't well\n supported by the community and likely has no maintainer.", :level=>:warn}
{"message":"<86>1 2016-01-05T18:38:32.550186+01:00 master1 snoopy[12006]: [uid:2009 username:wpoelman sid:11944 tty:(none) cwd:/home/wpoelman filename:/usr/bin/tr]: tr [:lower:] [:upper:]","@version":"1","@timestamp":"2016-01-05T17:38:32.550Z","host":"weedly.ugent.be","syslog_abspri":"86","syslog_version":"1","program":"snoopy","pid":"12006","uid":2009,"username":"wpoelman","sid":11944,"tty":"(none)","cwd":"/home/wpoelman","executable":"/usr/bin/tr","command":"tr [:lower:] [:upper:]","received_at":"2016-01-06T09:30:38.074Z","received_from":"%{@source_host}","@source_host":"master1","@message":"%{syslog_message}"}
{"message":"<86>1 2015-12-08T16:59:54.996042+01:00 gligar01 snoopy[30093]: - snoopy[30093]:: [uid:2540003 sid:29974 tty:/dev/pts/7 cwd:/vscmnt/gent_vulpix/_/user/home/gent/vsc400/vsc40003 filename:/user/home/gent/vsc400/vsc40003/easybuild_easyinstalled/bin/easy_install]: easy_install -U --prefix /user/home/gent/vsc400/vsc40003/easybuild_easyinstalled https://github.com/hpcugent/easybuild-framework/archive/develop.tar.gz","@version":"1","@timestamp":"2015-12-08T15:59:54.996Z","host":"weedly.ugent.be","syslog_abspri":"86","syslog_version":"1","program":"snoopy","pid":"30093","uid":2540003,"sid":29974,"tty":"/dev/pts/7","cwd":"/vscmnt/gent_vulpix/_/user/home/gent/vsc400/vsc40003","executable":"/user/home/gent/vsc400/vsc40003/easybuild_easyinstalled/bin/easy_install","command":"easy_install -U --prefix /user/home/gent/vsc400/vsc40003/easybuild_easyinstalled https://github.com/hpcugent/easybuild-framework/archive/develop.tar.gz","received_at":"2016-01-06T09:30:38.073Z","received_from":"%{@source_host}","@source_host":"gligar01","@message":"%{syslog_message}"}
2016-01-06 10:30:39,450 DEBUG runtest.RUNTEST MainThread Returning processed output list [({u'syslog_abspri': u'86', u'username': u'wpoelman', u'tty': u'(none)', u'uid': 2009, u'received_from': u'%{@source_host}', u'@timestamp': u'2016-01-05T17:38:32.550Z', u'pid': u'12006', u'executable': u'/usr/bin/tr', u'received_at': u'2016-01-06T09:30:38.074Z', u'host': u'weedly.ugent.be', u'program': u'snoopy', u'command': u'tr [:lower:] [:upper:]', u'@message': u'%{syslog_message}', u'sid': 11944, u'syslog_version': u'1', u'@source_host': u'master1', u'message': u'<86>1 2016-01-05T18:38:32.550186+01:00 master1 snoopy[12006]: [uid:2009 username:wpoelman sid:11944 tty:(none) cwd:/home/wpoelman filename:/usr/bin/tr]: tr [:lower:] [:upper:]', u'@version': u'1', u'cwd': u'/home/wpoelman'}, '{"message":"<86>1 2016-01-05T18:38:32.550186+01:00 master1 snoopy[12006]: [uid:2009 username:wpoelman sid:11944 tty:(none) cwd:/home/wpoelman filename:/usr/bin/tr]: tr [:lower:] [:upper:]","@version":"1","@timestamp":"2016-01-05T17:38:32.550Z","host":"weedly.ugent.be","syslog_abspri":"86","syslog_version":"1","program":"snoopy","pid":"12006","uid":2009,"username":"wpoelman","sid":11944,"tty":"(none)","cwd":"/home/wpoelman","executable":"/usr/bin/tr","command":"tr [:lower:] [:upper:]","received_at":"2016-01-06T09:30:38.074Z","received_from":"%{@source_host}","@source_host":"master1","@message":"%{syslog_message}"}'), ({u'syslog_abspri': u'86', u'received_from': u'%{@source_host}', u'tty': u'/dev/pts/7', u'uid': 2540003, u'@timestamp': u'2015-12-08T15:59:54.996Z', u'pid': u'30093', u'executable': u'/user/home/gent/vsc400/vsc40003/easybuild_easyinstalled/bin/easy_install', u'received_at': u'2016-01-06T09:30:38.073Z', u'host': u'weedly.ugent.be', u'program': u'snoopy', u'command': u'easy_install -U --prefix /user/home/gent/vsc400/vsc40003/easybuild_easyinstalled https://github.com/hpcugent/easybuild-framework/archive/develop.tar.gz', u'@message': u'%{syslog_message}', u'sid': 29974, u'syslog_version': u'1', u'@source_host': u'gligar01', u'message': u'<86>1 2015-12-08T16:59:54.996042+01:00 gligar01 snoopy[30093]: - snoopy[30093]:: [uid:2540003 sid:29974 tty:/dev/pts/7 cwd:/vscmnt/gent_vulpix/_/user/home/gent/vsc400/vsc40003 filename:/user/home/gent/vsc400/vsc40003/easybuild_easyinstalled/bin/easy_install]: easy_install -U --prefix /user/home/gent/vsc400/vsc40003/easybuild_easyinstalled https://github.com/hpcugent/easybuild-framework/archive/develop.tar.gz', u'@version': u'1', u'cwd': u'/vscmnt/gent_vulpix/_/user/home/gent/vsc400/vsc40003'}, '{"message":"<86>1 2015-12-08T16:59:54.996042+01:00 gligar01 snoopy[30093]: - snoopy[30093]:: [uid:2540003 sid:29974 tty:/dev/pts/7 cwd:/vscmnt/gent_vulpix/_/user/home/gent/vsc400/vsc40003 filename:/user/home/gent/vsc400/vsc40003/easybuild_easyinstalled/bin/easy_install]: easy_install -U --prefix /user/home/gent/vsc400/vsc40003/easybuild_easyinstalled https://github.com/hpcugent/easybuild-framework/archive/develop.tar.gz","@version":"1","@timestamp":"2015-12-08T15:59:54.996Z","host":"weedly.ugent.be","syslog_abspri":"86","syslog_version":"1","program":"snoopy","pid":"30093","uid":2540003,"sid":29974,"tty":"/dev/pts/7","cwd":"/vscmnt/gent_vulpix/_/user/home/gent/vsc400/vsc40003","executable":"/user/home/gent/vsc400/vsc40003/easybuild_easyinstalled/bin/easy_install","command":"easy_install -U --prefix /user/home/gent/vsc400/vsc40003/easybuild_easyinstalled https://github.com/hpcugent/easybuild-framework/archive/develop.tar.gz","received_at":"2016-01-06T09:30:38.073Z","received_from":"%{@source_host}","@source_host":"gligar01","@message":"%{syslog_message}"}')]
2016-01-06 10:30:39,450 ERROR runtest.RUNTEST MainThread key tty value (none) (type <type 'unicode'>), expected /dev/pts/7 (type <type 'str'>)
2016-01-06 10:30:39,451 DEBUG runtest.RUNTEST MainThread Full out {u'@message': u'%{syslog_message}',
u'@source_host': u'master1',
u'@timestamp': u'2016-01-05T17:38:32.550Z',
u'@version': u'1',
u'command': u'tr [:lower:] [:upper:]',
u'cwd': u'/home/wpoelman',
u'executable': u'/usr/bin/tr',
u'host': u'weedly.ugent.be',
u'message': u'<86>1 2016-01-05T18:38:32.550186+01:00 master1 snoopy[12006]: [uid:2009 username:wpoelman sid:11944 tty:(none) cwd:/home/wpoelman filename:/usr/bin/tr]: tr [:lower:] [:upper:]',
u'pid': u'12006',
u'program': u'snoopy',
u'received_at': u'2016-01-06T09:30:38.074Z',
u'received_from': u'%{@source_host}',
u'sid': 11944,
u'syslog_abspri': u'86',
u'syslog_version': u'1',
u'tty': u'(none)',
u'uid': 2009,
u'username': u'wpoelman'} from line {"message":"<86>1 2016-01-05T18:38:32.550186+01:00 master1 snoopy[12006]: [uid:2009 username:wpoelman sid:11944 tty:(none) cwd:/home/wpoelman filename:/usr/bin/tr]: tr [:lower:] [:upper:]","@version":"1","@timestamp":"2016-01-05T17:38:32.550Z","host":"weedly.ugent.be","syslog_abspri":"86","syslog_version":"1","program":"snoopy","pid":"12006","uid":2009,"username":"wpoelman","sid":11944,"tty":"(none)","cwd":"/home/wpoelman","executable":"/usr/bin/tr","command":"tr [:lower:] [:upper:]","received_at":"2016-01-06T09:30:38.074Z","received_from":"%{@source_host}","@source_host":"master1","@message":"%{syslog_message}"}
This does not happen always. It seems like logstash returns the log lines in random order? I'm using 2.1.1.