On Tue, 3 Mar 2015, Thomas D. wrote:

Rainer wrote:
side-activity: could you please apply this patch and see if the test now
succeeds on your system with the new tools:


https://github.com/rgerhards/rsyslog/commit/de082e425f3f6d430eb136a2fb230d58b7e9580e

Failing:


FAIL: imuxsock_logger.sh
========================

[imuxsock_logger.sh]: test imuxsock in rfc3164 mode
rsyslog.pid exists, trying to shut down rsyslogd process 29789.
rsyslogd started with pid  29974
imdiag[13500]: mainqueue empty
rsyslog.out.log ./resultdata/imuxsock_logger.log differ: byte 2, line 1
imuxsock_logger.sh failed
contents of rsyslog.out.log:
" root: test"
FAIL imuxsock_logger.sh (exit status: 1)


interesting... Could you record the raw message form me? Or a debug log?
For debug log, you can simply edit ./tests/diag.sh, search for DEBUG
variables on the first page (you'll know what I mean  when you look at that
page).

Please see the attached debug log.

Ok, if I'm reading the log correctly, here is the line that shows the message
delivered to rsyslog

6630.247443933:main Q:Reg/w0  : processBATCH: next msg 0: <5>Mar  3 19:17:10
vm-gentoo-x64 root: test

This is showing the message being pulled from the main queue, not the raw log arriving via uxsock, so it's possible it's already been manipulated

according to RFC5424, the header is PRI VERSION SP TIMESTAMP SP HOSTNAME

so if this is the raw log, this is not quite valid RFC5424, it would have " 1 " between the > and Mar (I was misremembering that the version was before the pri)

In the test config, there should be a template that it uses to generate this output. Can you try changing it to RSYSLOG_DebugFormat just to be sure that we are seeing the raw log? this will put a lot of other info in the rsyslog.out.log file, but will include both the parsed and the raw log.

David Lang
6630.135264056:main thread    : rsyslogd 8.8.0 startup, module path 
'../runtime/.libs:../.libs', 
cwd:/var/tmp/portage/app-admin/rsyslog-8.8.0/work/rsyslog-8.8.0/tests
6630.135307336:main thread    : setting default module load directory 
'/var/tmp/portage/app-admin/rsyslog-8.8.0/work/rsyslog-8.8.0/runtime/.libs/'
6630.135312309:main thread    : setting default module load directory 
'../runtime/.libs:../.libs'
6630.135338522:main thread    : caller requested object 'net', not found (iRet 
-3003)
6630.135344703:main thread    : Requested to load module 'lmnet'
6630.135349213:main thread    : loading module '../runtime/.libs/lmnet.so'
6630.135406671:main thread    : module lmnet of type 2 being loaded 
(keepType=0).
6630.135411189:main thread    : entry point 'isCompatibleWithFeature' not 
present in module
6630.135413313:main thread    : entry point 'setModCnf' not present in module
6630.135415382:main thread    : entry point 'getModCnfName' not present in 
module
6630.135417401:main thread    : entry point 'beginCnfLoad' not present in module
6630.135420232:main thread    : source file conf.c requested reference for 
module 'lmnet', reference count now 1
6630.135427913:main thread    : rsyslog runtime initialized, version 8.8.0, 
current users 1
6630.135445318:main thread    : source file rsyslogd.c requested reference for 
module 'lmnet', reference count now 2
6630.135810936:main thread    : GenerateLocalHostName uses 'vm-gentoo-x64'
6630.135821165:main thread    : deque option C, optarg ''
6630.135824618:main thread    : deque option n, optarg ''
6630.135827437:main thread    : deque option i, optarg 'rsyslog.pid'
6630.135830007:main thread    : deque option f, optarg 
'./testsuites/imuxsock_logger.conf'
6630.135841640:main thread    : omfile: using transactional output interface.
6630.135857246:main thread    : module builtin:omfile of type 1 being loaded 
(keepType=0).
6630.135861352:main thread    : module config name is 'omfile'
6630.135863631:main thread    : module builtin:omfile supports rsyslog v6 
config interface
6630.135866976:main thread    : entry point 'activateCnfPrePrivDrop' not 
present in module
6630.135870476:main thread    : entry point 'SetShutdownImmdtPtr' not present 
in module
6630.135872819:main thread    : entry point 'doAction' not present in module
6630.135874997:main thread    : entry point 'endTransaction' not present in 
module
6630.135878651:main thread    : module builtin:ompipe of type 1 being loaded 
(keepType=0).
6630.135881740:main thread    : module config name is 'ompipe'
6630.135883808:main thread    : module builtin:ompipe supports rsyslog v6 
config interface
6630.135886921:main thread    : entry point 'activateCnfPrePrivDrop' not 
present in module
6630.135890106:main thread    : entry point 'SetShutdownImmdtPtr' not present 
in module
6630.135892238:main thread    : entry point 'beginTransaction' not present in 
module
6630.135894390:main thread    : entry point 'commitTransaction' not present in 
module
6630.135896431:main thread    : entry point 'endTransaction' not present in 
module
6630.135899887:main thread    : module builtin-shell of type 1 being loaded 
(keepType=0).
6630.135902391:main thread    : entry point 'setModCnf' not present in module
6630.135904411:main thread    : entry point 'getModCnfName' not present in 
module
6630.135906315:main thread    : entry point 'beginCnfLoad' not present in module
6630.135909010:main thread    : entry point 'doHUP' not present in module
6630.135910917:main thread    : entry point 'SetShutdownImmdtPtr' not present 
in module
6630.135912780:main thread    : entry point 'beginTransaction' not present in 
module
6630.135914722:main thread    : entry point 'commitTransaction' not present in 
module
6630.135916567:main thread    : entry point 'endTransaction' not present in 
module
6630.135918480:main thread    : entry point 'newActInst' not present in module
6630.135921177:main thread    : module builtin:omdiscard of type 1 being loaded 
(keepType=0).
6630.135923705:main thread    : entry point 'setModCnf' not present in module
6630.135925675:main thread    : entry point 'getModCnfName' not present in 
module
6630.135931511:main thread    : entry point 'beginCnfLoad' not present in module
6630.135934650:main thread    : entry point 'doHUP' not present in module
6630.135936734:main thread    : entry point 'SetShutdownImmdtPtr' not present 
in module
6630.135938758:main thread    : entry point 'beginTransaction' not present in 
module
6630.135940792:main thread    : entry point 'commitTransaction' not present in 
module
6630.135942729:main thread    : entry point 'endTransaction' not present in 
module
6630.135944751:main thread    : entry point 'newActInst' not present in module
6630.135948329:main thread    : source file omfwd.c requested reference for 
module 'lmnet', reference count now 3
6630.135956534:main thread    : module builtin:omfwd of type 1 being loaded 
(keepType=0).
6630.135959914:main thread    : module config name is 'omfwd'
6630.135962127:main thread    : module builtin:omfwd supports rsyslog v6 config 
interface
6630.135965314:main thread    : entry point 'activateCnfPrePrivDrop' not 
present in module
6630.135968462:main thread    : entry point 'doHUP' not present in module
6630.135970664:main thread    : entry point 'SetShutdownImmdtPtr' not present 
in module
6630.135972925:main thread    : entry point 'doAction' not present in module
6630.135975139:main thread    : entry point 'endTransaction' not present in 
module
6630.135978570:main thread    : module builtin:omusrmsg of type 1 being loaded 
(keepType=0).
6630.135981175:main thread    : entry point 'setModCnf' not present in module
6630.135983390:main thread    : module config name is 'omusrmsg'
6630.135985476:main thread    : entry point 'beginCnfLoad' not present in module
6630.135988290:main thread    : entry point 'doHUP' not present in module
6630.135990314:main thread    : entry point 'SetShutdownImmdtPtr' not present 
in module
6630.135992302:main thread    : entry point 'beginTransaction' not present in 
module
6630.135994320:main thread    : entry point 'commitTransaction' not present in 
module
6630.135996303:main thread    : entry point 'endTransaction' not present in 
module
6630.135999720:main thread    : rfc5424 parser init called
6630.136002044:main thread    : GetParserName addr 0x44eec0
6630.136004217:main thread    : module builtin:pmrfc5424 of type 3 being loaded 
(keepType=0).
6630.136006347:main thread    : entry point 'setModCnf' not present in module
6630.136008294:main thread    : entry point 'getModCnfName' not present in 
module
6630.136010248:main thread    : entry point 'beginCnfLoad' not present in module
6630.136012188:main thread    : entry point 'parse2' not present in module
6630.136014933:main thread    : DDDDD: added parser 'rsyslog.rfc5424' to list 
0x6904b0
6630.136016952:main thread    : Parser 'rsyslog.rfc5424' added to list of 
available parsers.
6630.136019934:main thread    : rfc3164 parser init called
6630.136022666:main thread    : module builtin:pmrfc3164 of type 3 being loaded 
(keepType=0).
6630.136024837:main thread    : entry point 'setModCnf' not present in module
6630.136026776:main thread    : entry point 'getModCnfName' not present in 
module
6630.136028657:main thread    : entry point 'beginCnfLoad' not present in module
6630.136030523:main thread    : entry point 'parse2' not present in module
6630.136032818:main thread    : DDDDD: added parser 'rsyslog.rfc3164' to list 
0x6904b0
6630.136034702:main thread    : Parser 'rsyslog.rfc3164' added to list of 
available parsers.
6630.136036812:main thread    : DDDDD: added parser 'rsyslog.rfc5424' to list 
0x6904a8
6630.136038752:main thread    : Parser 'rsyslog.rfc5424' added to default 
parser set.
6630.136040757:main thread    : DDDDD: added parser 'rsyslog.rfc3164' to list 
0x6904a8
6630.136042584:main thread    : Parser 'rsyslog.rfc3164' added to default 
parser set.
6630.136044811:main thread    : rsyslog standard file format strgen init 
called, compiled with version 8.8.0
6630.136047103:main thread    : module builtin:smfile of type 4 being loaded 
(keepType=0).
6630.136049111:main thread    : entry point 'isCompatibleWithFeature' not 
present in module
6630.136054019:main thread    : entry point 'setModCnf' not present in module
6630.136056111:main thread    : entry point 'getModCnfName' not present in 
module
6630.136058054:main thread    : entry point 'beginCnfLoad' not present in module
6630.136061108:main thread    : Strgen 'RSYSLOG_FileFormat' added to list of 
available strgens.
6630.136063594:main thread    : traditional file format strgen init called, 
compiled with version 8.8.0
6630.136065945:main thread    : module builtin:smtradfile of type 4 being 
loaded (keepType=0).
6630.136067950:main thread    : entry point 'isCompatibleWithFeature' not 
present in module
6630.136069856:main thread    : entry point 'setModCnf' not present in module
6630.136071737:main thread    : entry point 'getModCnfName' not present in 
module
6630.136073580:main thread    : entry point 'beginCnfLoad' not present in module
6630.136076009:main thread    : Strgen 'RSYSLOG_TraditionalFileFormat' added to 
list of available strgens.
6630.136078362:main thread    : rsyslog standard (network) forward format 
strgen init called, compiled with version 8.8.0
6630.136080628:main thread    : module builtin:smfwd of type 4 being loaded 
(keepType=0).
6630.136082596:main thread    : entry point 'isCompatibleWithFeature' not 
present in module
6630.136084519:main thread    : entry point 'setModCnf' not present in module
6630.136086389:main thread    : entry point 'getModCnfName' not present in 
module
6630.136088242:main thread    : entry point 'beginCnfLoad' not present in module
6630.136090490:main thread    : Strgen 'RSYSLOG_ForwardFormat' added to list of 
available strgens.
6630.136092854:main thread    : rsyslog traditional (network) forward format 
strgen init called, compiled with version 8.8.0
6630.136095126:main thread    : module builtin:smtradfwd of type 4 being loaded 
(keepType=0).
6630.136097148:main thread    : entry point 'isCompatibleWithFeature' not 
present in module
6630.136099053:main thread    : entry point 'setModCnf' not present in module
6630.136100957:main thread    : entry point 'getModCnfName' not present in 
module
6630.136102835:main thread    : entry point 'beginCnfLoad' not present in module
6630.136105185:main thread    : Strgen 'RSYSLOG_TraditionalForwardFormat' added 
to list of available strgens.
6630.136107435:main thread    : doing legacy config system init
6630.136142545:main thread    : tplAddLine processing template 
'RSYSLOG_DebugFormat'
6630.136158996:main thread    : tplAddLine processing template 
'RSYSLOG_SyslogProtocol23Format'
6630.136164881:main thread    : tplAddLine processing template 
'RSYSLOG_FileFormat'
6630.136167693:main thread    : template bound to strgen 'RSYSLOG_FileFormat'
6630.136170153:main thread    : tplAddLine processing template 
'RSYSLOG_TraditionalFileFormat'
6630.136172355:main thread    : template bound to strgen 
'RSYSLOG_TraditionalFileFormat'
6630.136174645:main thread    : tplAddLine processing template ' WallFmt'
6630.136178190:main thread    : tplAddLine processing template 
'RSYSLOG_ForwardFormat'
6630.136180518:main thread    : template bound to strgen 'RSYSLOG_ForwardFormat'
6630.136182788:main thread    : tplAddLine processing template 
'RSYSLOG_TraditionalForwardFormat'
6630.136185072:main thread    : template bound to strgen 
'RSYSLOG_TraditionalForwardFormat'
6630.136187264:main thread    : tplAddLine processing template ' StdUsrMsgFmt'
6630.136190830:main thread    : tplAddLine processing template ' StdDBFmt'
6630.136198120:main thread    : tplAddLine processing template 
'RSYSLOG_SysklogdFileFormat'
6630.136202108:main thread    : tplAddLine processing template ' StdPgSQLFmt'
6630.136207492:main thread    : tplAddLine processing template ' StdJSONFmt'
6630.136213276:main thread    : tplAddLine processing template 
'RSYSLOG_omudpspoofDfltSourceTpl'
6630.136238009:main thread    : config parser: pushed file 
./testsuites/imuxsock_logger.conf on top of stack
6630.136252727:main thread    : requested to include config file 
'diag-common.conf'
6630.136268529:main thread    : config parser: pushed file diag-common.conf on 
top of stack
6630.136280408:main thread    : cnf:global:cfsysline: $ModLoad 
../plugins/imdiag/.libs/imdiag
6630.136287783:main thread    : Requested to load module 
'../plugins/imdiag/.libs/imdiag'
6630.136291051:main thread    : loading module 
'../plugins/imdiag/.libs/imdiag.so'
6630.136328781:main thread    : source file imdiag.c requested reference for 
module 'lmnet', reference count now 4
6630.136333802:main thread    : caller requested object 'netstrm', not found 
(iRet -3003)
6630.136338699:main thread    : Requested to load module 'lmnetstrms'
6630.136341390:main thread    : loading module '../runtime/.libs/lmnetstrms.so'
6630.136375574:main thread    : doing nsselClassInit
6630.136380823:main thread    : doing nspollClassInit
6630.136384694:main thread    : module lmnetstrms of type 2 being loaded 
(keepType=0).
6630.136387131:main thread    : entry point 'isCompatibleWithFeature' not 
present in module
6630.136389164:main thread    : entry point 'setModCnf' not present in module
6630.136391109:main thread    : entry point 'getModCnfName' not present in 
module
6630.136393051:main thread    : entry point 'beginCnfLoad' not present in module
6630.136395478:main thread    : source file imdiag.c requested reference for 
module 'lmnetstrms', reference count now 1
6630.136398255:main thread    : caller requested object 'tcps_sess', not found 
(iRet -3003)
6630.136400220:main thread    : Requested to load module 'lmtcpsrv'
6630.136402607:main thread    : loading module '../runtime/.libs/lmtcpsrv.so'
6630.136408778:main thread    : loading module '../.libs/lmtcpsrv.so'
6630.136451278:main thread    : source file tcps_sess.c requested reference for 
module 'lmnetstrms', reference count now 2
6630.136459575:main thread    : source file tcpsrv.c requested reference for 
module 'lmnet', reference count now 5
6630.136462852:main thread    : source file tcpsrv.c requested reference for 
module 'lmnetstrms', reference count now 3
6630.136468128:main thread    : module lmtcpsrv of type 2 being loaded 
(keepType=0).
6630.136470609:main thread    : entry point 'isCompatibleWithFeature' not 
present in module
6630.136472638:main thread    : entry point 'setModCnf' not present in module
6630.136474595:main thread    : entry point 'getModCnfName' not present in 
module
6630.136476559:main thread    : entry point 'beginCnfLoad' not present in module
6630.136478919:main thread    : source file imdiag.c requested reference for 
module 'lmtcpsrv', reference count now 1
6630.136481630:main thread    : source file imdiag.c requested reference for 
module 'lmtcpsrv', reference count now 2
6630.136490273:main thread    : module ../plugins/imdiag/.libs/imdiag of type 0 
being loaded (keepType=0).
6630.136493014:main thread    : entry point 'setModCnf' not present in module
6630.136495040:main thread    : entry point 'getModCnfName' not present in 
module
6630.136496994:main thread    : entry point 'beginCnfLoad' not present in module
6630.136499206:main thread    : entry point 'newInpInst' not present in module
6630.136502526:main thread    : cnf:global:cfsysline: $IMDiagServerRun 13500
6630.136506435:main thread    : doGetWord: get newval '13500' (len 5), hdlr 
0x7f9a3edfd210
6630.136511286:main thread    : ratelimit:tcperver:new 
ratelimiter:bReduceRepeatMsgs 0
6630.136515324:main thread    : cnf:global:cfsysline: $template 
startupfile,"rsyslogd.started" # trick to use relative path names!
6630.136518508:main thread    : tplAddLine processing template 'startupfile'
6630.136522900:main thread    : lexer: propfilt is ':syslogtag, contains, 
"rsyslogd"'
6630.136528557:main thread    : tried selector action for builtin:omfile: 0
6630.136531001:main thread    : Module builtin:omfile processes this action.
6630.136536332:main thread    : template: 'RSYSLOG_FileFormat' assigned
6630.136538879:main thread    : template: 'startupfile' assigned
6630.136544168:main thread    : action 1 queue: parameter dump:
6630.136546635:main thread    : action 1 queue: queue.filename '[NONE]'
6630.136548623:main thread    : action 1 queue: queue.size: 1000
6630.136550613:main thread    : action 1 queue: queue.dequeuebatchsize: 16
6630.136555526:main thread    : action 1 queue: queue.maxdiskspace: 0
6630.136557716:main thread    : action 1 queue: queue.highwatermark: -1
6630.136559708:main thread    : action 1 queue: queue.lowwatermark: -1
6630.136561612:main thread    : action 1 queue: queue.fulldelaymark: -1
6630.136563487:main thread    : action 1 queue: queue.lightdelaymark: -1
6630.136565421:main thread    : action 1 queue: queue.discardmark: 980
6630.136567260:main thread    : action 1 queue: queue.discardseverity: 8
6630.136569096:main thread    : action 1 queue: queue.checkpointinterval: 0
6630.136570929:main thread    : action 1 queue: queue.syncqueuefiles: 0
6630.136572904:main thread    : action 1 queue: queue.type: 3 [Direct]
6630.136574724:main thread    : action 1 queue: queue.workerthreads: 1
6630.136576587:main thread    : action 1 queue: queue.timeoutshutdown: 0
6630.136578593:main thread    : action 1 queue: queue.timeoutactioncompletion: 
1000
6630.136580481:main thread    : action 1 queue: queue.timeoutenqueue: 50
6630.136582423:main thread    : action 1 queue: 
queue.timeoutworkerthreadshutdown: 60000
6630.136584316:main thread    : action 1 queue: 
queue.workerthreadminimummessages: -1
6630.136586223:main thread    : action 1 queue: queue.maxfilesize: 1048576
6630.136588043:main thread    : action 1 queue: queue.saveonshutdown: 1
6630.136589879:main thread    : action 1 queue: queue.dequeueslowdown: 0
6630.136591716:main thread    : action 1 queue: queue.dequeuetimebegin: 0
6630.136593556:main thread    : action 1 queue: queue.dequeuetimeend: 25
6630.136595534:main thread    : Action 0x7f9a3f076100: queue 0x7f9a3f07a280 
created
6630.136600521:main thread    : config parser: reached end of file 
diag-common.conf
6630.136603051:main thread    : config parser: resume parsing of file 
./testsuites/imuxsock_logger.conf at line 2
6630.136606296:main thread    : Decoding property-based filter ':syslogtag, 
contains, "rsyslogd"'
6630.136611132:main thread    : cnf:global:script
6630.136617015:main thread    : cnf:global:obj: obj: 'module'
6630.136621215:main thread    : nvlst 0x7f9a3f01b7f0:
6630.136623642:main thread    :         name: 'sysSock.use', value 'off'
6630.136625896:main thread    :         name: 'load', value 
'../plugins/imuxsock/.libs/imuxsock'
6630.136629456:main thread    : nvlstGetParam: name 'load', type 13, 
valnode->bUsed 0
6630.136632801:main thread    : modulesProcessCnf params:
6630.136634956:main thread    : load:  '../plugins/imuxsock/.libs/imuxsock'
6630.136640582:main thread    : Requested to load module 
'../plugins/imuxsock/.libs/imuxsock'
6630.136643047:main thread    : loading module 
'../plugins/imuxsock/.libs/imuxsock.so'
6630.136689729:main thread    : imuxsock version 8.8.0 initializing
6630.136694787:main thread    : rsyslog/glbl: using '127.0.0.1' as localhost IP
6630.136716635:main thread    : module ../plugins/imuxsock/.libs/imuxsock of 
type 0 being loaded (keepType=0).
6630.136720017:main thread    : module config name is 'imuxsock'
6630.136722260:main thread    : module ../plugins/imuxsock/.libs/imuxsock 
supports rsyslog v6 config interface
6630.136726470:main thread    : nvlstGetParam: name 'syssock.use', type 4, 
valnode->bUsed 0
6630.136729389:main thread    : module (global) param blk for imuxsock:
6630.136731364:main thread    : syssock.use: 0
6630.136736146:main thread    : syssock.name: (unset)
6630.136740697:main thread    : syssock.unlink: (unset)
6630.136745091:main thread    : syssock.ignoretimestamp: (unset)
6630.136749533:main thread    : syssock.ignoreownmessages: (unset)
6630.136753919:main thread    : syssock.flowcontrol: (unset)
6630.136758330:main thread    : syssock.usesystimestamp: (unset)
6630.136762673:main thread    : syssock.annotate: (unset)
6630.136766968:main thread    : syssock.parsetrusted: (unset)
6630.136771322:main thread    : syssock.usepidfromsystem: (unset)
6630.136775702:main thread    : syssock.ratelimit.interval: (unset)
6630.136780031:main thread    : syssock.ratelimit.burst: (unset)
6630.136784408:main thread    : syssock.ratelimit.severity: (unset)
6630.136795204:main thread    : cnf:global:obj: obj: 'input'
6630.136799229:main thread    : nvlst 0x7f9a3f01b460:
6630.136801208:main thread    :         name: 'Socket', value 'testbench_socket'
6630.136803197:main thread    :         name: 'type', value 'imuxsock'
6630.136805545:main thread    : nvlstGetParam: name 'type', type 14, 
valnode->bUsed 0
6630.136808142:main thread    : input param blk after inputProcessCnf:
6630.136810087:main thread    : type:  'imuxsock'
6630.136815403:main thread    : newInpInst (imuxsock)
6630.136817773:main thread    : nvlstGetParam: name 'socket', type 14, 
valnode->bUsed 0
6630.136820108:main thread    : input param blk in imuxsock:
6630.136822005:main thread    : socket:  'testbench_socket'
6630.136826766:main thread    : unlink: (unset)
6630.136831115:main thread    : createpath: (unset)
6630.136835429:main thread    : parsetrusted: (unset)
6630.136839891:main thread    : ignoreownmessages: (unset)
6630.136844269:main thread    : hostname: (unset)
6630.136848617:main thread    : ignoretimestamp: (unset)
6630.136852996:main thread    : flowcontrol: (unset)
6630.136857344:main thread    : usesystimestamp: (unset)
6630.136861670:main thread    : annotate: (unset)
6630.136866034:main thread    : usepidfromsystem: (unset)
6630.136870346:main thread    : ratelimit.interval: (unset)
6630.136874738:main thread    : ratelimit.burst: (unset)
6630.136879171:main thread    : ratelimit.severity: (unset)
6630.136886408:main thread    : cnf:global:obj: obj: 'template'
6630.136890090:main thread    : nvlst 0x7f9a3f01b7f0:
6630.136891989:main thread    :         name: 'string', value '%msg:%
'
6630.136894042:main thread    :         name: 'type', value 'string'
6630.136896018:main thread    :         name: 'name', value 'outfmt'
6630.136898248:main thread    : nvlstGetParam: name 'name', type 14, 
valnode->bUsed 0
6630.136900448:main thread    : nvlstGetParam: name 'type', type 14, 
valnode->bUsed 0
6630.136902560:main thread    : nvlstGetParam: name 'string', type 14, 
valnode->bUsed 0
6630.136904705:main thread    : name:  'outfmt'
6630.136909458:main thread    : type:  'string'
6630.136914077:main thread    : string:  '%msg:%
'
6630.136918782:main thread    : plugin: (unset)
6630.136923240:main thread    : subtree: (unset)
6630.136927625:main thread    : option.stdsql: (unset)
6630.136931974:main thread    : option.sql: (unset)
6630.136936433:main thread    : option.json: (unset)
6630.136943854:main thread    : tried selector action for builtin:omfile: 0
6630.136946240:main thread    : Module builtin:omfile processes this action.
6630.136948739:main thread    : template: 'outfmt' assigned
6630.136952280:main thread    : action 2 queue: parameter dump:
6630.136954474:main thread    : action 2 queue: queue.filename '[NONE]'
6630.136956416:main thread    : action 2 queue: queue.size: 1000
6630.136958304:main thread    : action 2 queue: queue.dequeuebatchsize: 16
6630.136960212:main thread    : action 2 queue: queue.maxdiskspace: 0
6630.136962117:main thread    : action 2 queue: queue.highwatermark: -1
6630.136963989:main thread    : action 2 queue: queue.lowwatermark: -1
6630.136965837:main thread    : action 2 queue: queue.fulldelaymark: -1
6630.136967736:main thread    : action 2 queue: queue.lightdelaymark: -1
6630.136969616:main thread    : action 2 queue: queue.discardmark: 980
6630.136971479:main thread    : action 2 queue: queue.discardseverity: 8
6630.136973352:main thread    : action 2 queue: queue.checkpointinterval: 0
6630.136975248:main thread    : action 2 queue: queue.syncqueuefiles: 0
6630.136977183:main thread    : action 2 queue: queue.type: 3 [Direct]
6630.136979051:main thread    : action 2 queue: queue.workerthreads: 1
6630.136980932:main thread    : action 2 queue: queue.timeoutshutdown: 0
6630.136982815:main thread    : action 2 queue: queue.timeoutactioncompletion: 
1000
6630.136984694:main thread    : action 2 queue: queue.timeoutenqueue: 50
6630.136986547:main thread    : action 2 queue: 
queue.timeoutworkerthreadshutdown: 60000
6630.136988399:main thread    : action 2 queue: 
queue.workerthreadminimummessages: -1
6630.136992913:main thread    : action 2 queue: queue.maxfilesize: 1048576
6630.136994951:main thread    : action 2 queue: queue.saveonshutdown: 1
6630.136996858:main thread    : action 2 queue: queue.dequeueslowdown: 0
6630.136998732:main thread    : action 2 queue: queue.dequeuetimebegin: 0
6630.137000583:main thread    : action 2 queue: queue.dequeuetimeend: 25
6630.137002560:main thread    : Action 0x7f9a3f076200: queue 0x7f9a3f07a600 
created
6630.137005099:main thread    : config parser: reached end of file 
./testsuites/imuxsock_logger.conf
6630.137007282:main thread    : config parser: parsing completed
6630.137009554:main thread    : Decoding traditional PRI filter '*.notice'
6630.137011841:main thread    : symbolic name: notice ==> 5
6630.137017385:main thread    : cnf:global:script
6630.137019783:main thread    : Number of actions in this configuration: 2
6630.137021893:main thread    : begin ruleset optimization phase
6630.137023997:main thread    : ruleset 'RSYSLOG_DefaultRuleset' before 
optimization:
6630.137026336:main thread    : ruleset 0x7f9a3f064500: rsyslog ruleset 
RSYSLOG_DefaultRuleset:
6630.137028551:main thread    : PROPFILT
6630.137030455:main thread    :         Property.: 'syslogtag'
6630.137032326:main thread    :         Operation: 'contains'
6630.137035872:main thread    :         Value....: 'rsyslogd'
6630.137037677:main thread    : THEN
6630.137039526:main thread    :   ACTION 0 [builtin:omfile:?startupfile]
6630.137043134:main thread    : END PROPFILT
6630.137044954:main thread    : PRIFILT '*.notice'
6630.137046721:main thread    : pmask: 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
6630.137086095:main thread    :   ACTION 1 
[builtin:omfile:./rsyslog.out.log;outfmt]
6630.137089518:main thread    : END PRIFILT
6630.137091443:main thread    : ruleset 0x7f9a3f064500: ruleset 
RSYSLOG_DefaultRuleset assigned parser list:
6630.137094042:main thread    : ruleset 'RSYSLOG_DefaultRuleset' after 
optimization:
6630.137095984:main thread    : ruleset 0x7f9a3f064500: rsyslog ruleset 
RSYSLOG_DefaultRuleset:
6630.137097837:main thread    : PROPFILT
6630.137099606:main thread    :         Property.: 'syslogtag'
6630.137101294:main thread    :         Operation: 'contains'
6630.137104480:main thread    :         Value....: 'rsyslogd'
6630.137106202:main thread    : THEN
6630.137107884:main thread    :   ACTION 0 [builtin:omfile:?startupfile]
6630.137111172:main thread    : END PROPFILT
6630.137112948:main thread    : PRIFILT '*.notice'
6630.137114649:main thread    : pmask: 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
6630.137153603:main thread    :   ACTION 1 
[builtin:omfile:./rsyslog.out.log;outfmt]
6630.137156960:main thread    : END PRIFILT
6630.137158784:main thread    : ruleset 0x7f9a3f064500: ruleset 
RSYSLOG_DefaultRuleset assigned parser list:
6630.137160743:main thread    : ruleset optimization phase finished.
6630.137162631:main thread    : telling rsyslog core that config load for 
0x7f9a3f05e180 is done
6630.137165416:main thread    : Timezone information table (0 entries):
6630.137167608:main thread    : telling modules that config load for 
0x7f9a3f05e180 is done
6630.137169588:main thread    : beginCnfLoad(0x44b4c0) for module 
'builtin:omfile'
6630.137171403:main thread    : calling endCnfLoad() for module 'builtin:omfile'
6630.137173295:main thread    : beginCnfLoad(0x44e060) for module 
'builtin:ompipe'
6630.137175190:main thread    : calling endCnfLoad() for module 'builtin:ompipe'
6630.137177220:main thread    : beginCnfLoad((nil)) for module 'builtin-shell'
6630.137179190:main thread    : beginCnfLoad((nil)) for module 
'builtin:omdiscard'
6630.137181046:main thread    : beginCnfLoad(0x448780) for module 
'builtin:omfwd'
6630.137182853:main thread    : calling endCnfLoad() for module 'builtin:omfwd'
6630.137184776:main thread    : beginCnfLoad((nil)) for module 
'builtin:omusrmsg'
6630.137186696:main thread    : beginCnfLoad((nil)) for module 
'builtin:pmrfc5424'
6630.137188549:main thread    : beginCnfLoad((nil)) for module 
'builtin:pmrfc3164'
6630.137192753:main thread    : beginCnfLoad((nil)) for module 'builtin:smfile'
6630.137194753:main thread    : beginCnfLoad((nil)) for module 
'builtin:smtradfile'
6630.137196601:main thread    : beginCnfLoad((nil)) for module 'builtin:smfwd'
6630.137198423:main thread    : beginCnfLoad((nil)) for module 
'builtin:smtradfwd'
6630.137200285:main thread    : beginCnfLoad((nil)) for module 
'../plugins/imdiag/.libs/imdiag'
6630.137202281:main thread    : beginCnfLoad(0x7f9a3e7e8d10) for module 
'../plugins/imuxsock/.libs/imuxsock'
6630.137204223:main thread    : calling endCnfLoad() for module 
'../plugins/imuxsock/.libs/imuxsock'
6630.137206247:main thread    : telling modules to check config 0x7f9a3f05e180
6630.137208242:main thread    : module builtin:omfile tells us config can be 
activated
6630.137210144:main thread    : module builtin:ompipe tells us config can be 
activated
6630.137212110:main thread    : module builtin:omfwd tells us config can be 
activated
6630.137214100:main thread    : module ../plugins/imuxsock/.libs/imuxsock tells 
us config can be activated
6630.137216156:main thread    : rsyslog finished loading master config 
0x7f9a3f05e180
6630.137218110:main thread    : configuration object 0x7f9a3f05e180
6630.137219834:main thread    : Global Settings:
6630.137221661:main thread    :   bDebugPrintTemplateList.............: 1
6630.137223460:main thread    :   bDebugPrintModuleList               : 0
6630.137225184:main thread    :   bDebugPrintCfSysLineHandlerList.....: 0
6630.137226926:main thread    :   bLogStatusMsgs                      : 1
6630.137228649:main thread    :   bErrMsgToStderr.....................: 1
6630.137230441:main thread    :   drop Msgs with malicious PTR Record : 0
6630.137232195:main thread    : All Rulesets:
6630.137234060:main thread    : ruleset 0x7f9a3f064500: rsyslog ruleset 
RSYSLOG_DefaultRuleset:
6630.137235850:main thread    : PROPFILT
6630.137237597:main thread    :         Property.: 'syslogtag'
6630.137239292:main thread    :         Operation: 'contains'
6630.137242381:main thread    :         Value....: 'rsyslogd'
6630.137244086:main thread    : THEN
6630.137245748:main thread    :   ACTION 0 [builtin:omfile:?startupfile]
6630.137248993:main thread    : END PROPFILT
6630.137250754:main thread    : PRIFILT '*.notice'
6630.137252464:main thread    : pmask: 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
6630.137290842:main thread    :   ACTION 1 
[builtin:omfile:./rsyslog.out.log;outfmt]
6630.137294127:main thread    : END PRIFILT
6630.137295940:main thread    : ruleset 0x7f9a3f064500: ruleset 
RSYSLOG_DefaultRuleset assigned parser list:
6630.137297818:main thread    : End of Rulesets.
6630.137299554:main thread    : 
6630.137301473:main thread    : Template: Name='RSYSLOG_DebugFormat' 
6630.137304882:main thread    :         Entry(7f9a3f06c0c0): type 1, 
(CONSTANT), value: 'Debug line with all properties:
FROMHOST: ''
6630.137309781:main thread    :         Entry(7f9a3f06c180): type 2, (FIELD), 
value: '7' 
6630.137314515:main thread    :         Entry(7f9a3f06c240): type 1, 
(CONSTANT), value: '', fromhost-ip: ''
6630.137319038:main thread    :         Entry(7f9a3f06c300): type 2, (FIELD), 
value: '8' 
6630.137323588:main thread    :         Entry(7f9a3f06c3c0): type 1, 
(CONSTANT), value: '', HOSTNAME: ''
6630.137328114:main thread    :         Entry(7f9a3f06c480): type 2, (FIELD), 
value: '3' 
6630.137332707:main thread    :         Entry(7f9a3f06c540): type 1, 
(CONSTANT), value: '', PRI: '
6630.137337248:main thread    :         Entry(7f9a3f06c600): type 2, (FIELD), 
value: '9' 
6630.137341815:main thread    :         Entry(7f9a3f06c6c0): type 1, 
(CONSTANT), value: ',
syslogtag ''
6630.137346387:main thread    :         Entry(7f9a3f06c780): type 2, (FIELD), 
value: '4' 
6630.137350922:main thread    :         Entry(7f9a3f06c840): type 1, 
(CONSTANT), value: '', programname: ''
6630.137355462:main thread    :         Entry(7f9a3f06c900): type 2, (FIELD), 
value: '17' 
6630.137360027:main thread    :         Entry(7f9a3f06c9c0): type 1, 
(CONSTANT), value: '', APP-NAME: ''
6630.137364603:main thread    :         Entry(7f9a3f06ca80): type 2, (FIELD), 
value: '20' 
6630.137369203:main thread    :         Entry(7f9a3f06cb40): type 1, 
(CONSTANT), value: '', PROCID: ''
6630.137376086:main thread    :         Entry(7f9a3f06cc00): type 2, (FIELD), 
value: '21' 
6630.137380778:main thread    :         Entry(7f9a3f06ccc0): type 1, 
(CONSTANT), value: '', MSGID: ''
6630.137385326:main thread    :         Entry(7f9a3f06cd80): type 2, (FIELD), 
value: '22' 
6630.137389869:main thread    :         Entry(7f9a3f06ce40): type 1, 
(CONSTANT), value: '',
TIMESTAMP: ''
6630.137394510:main thread    :         Entry(7f9a3f06cf00): type 2, (FIELD), 
value: '2' 
6630.137399118:main thread    :         Entry(7f9a3f06cfc0): type 1, 
(CONSTANT), value: '', STRUCTURED-DATA: ''
6630.137403789:main thread    :         Entry(7f9a3f06d080): type 2, (FIELD), 
value: '19' 
6630.137408344:main thread    :         Entry(7f9a3f06d140): type 1, 
(CONSTANT), value: '',
msg: ''
6630.137412940:main thread    :         Entry(7f9a3f06d200): type 2, (FIELD), 
value: '1' 
6630.137417447:main thread    :         Entry(7f9a3f06d2c0): type 1, 
(CONSTANT), value: ''
escaped msg: ''
6630.137421993:main thread    :         Entry(7f9a3f06d380): type 2, (FIELD), 
value: '1' [drop control-characters] [COMPLEX]
6630.137429428:main thread    :         Entry(7f9a3f06d440): type 1, 
(CONSTANT), value: ''
inputname: '
6630.137434068:main thread    :         Entry(7f9a3f06d500): type 2, (FIELD), 
value: '6' 
6630.137438743:main thread    :         Entry(7f9a3f06d5c0): type 1, 
(CONSTANT), value: ' rawmsg: ''
6630.137443381:main thread    :         Entry(7f9a3f06d680): type 2, (FIELD), 
value: '5' 
6630.137447935:main thread    :         Entry(7f9a3f06d740): type 1, 
(CONSTANT), value: ''
$!:'
6630.137452557:main thread    :         Entry(7f9a3f06d800): type 2, (FIELD), 
value: '200' [EE-Property: '!'] 
6630.137458710:main thread    :         Entry(7f9a3f06d8c0): type 1, 
(CONSTANT), value: '
$.:'
6630.137463329:main thread    :         Entry(7f9a3f06d980): type 2, (FIELD), 
value: '202' [Local Var: '!'] 
6630.137469381:main thread    :         Entry(7f9a3f06da40): type 1, 
(CONSTANT), value: '
$/:'
6630.137473962:main thread    :         Entry(7f9a3f06db00): type 2, (FIELD), 
value: '203' 
6630.137478504:main thread    :         Entry(7f9a3f06dbc0): type 1, 
(CONSTANT), value: '

'
6630.137483116:main thread    : Template: Name='RSYSLOG_SyslogProtocol23Format' 
6630.137486313:main thread    :         Entry(7f9a3f06dc80): type 1, 
(CONSTANT), value: '<'
6630.137490967:main thread    :         Entry(7f9a3f06dd40): type 2, (FIELD), 
value: '9' 
6630.137495522:main thread    :         Entry(7f9a3f06de00): type 1, 
(CONSTANT), value: '>1 '
6630.137500131:main thread    :         Entry(7f9a3f06dec0): type 2, (FIELD), 
value: '2' [Format as RFC3339-Date] [COMPLEX]
6630.137507520:main thread    :         Entry(7f9a3f06df80): type 1, 
(CONSTANT), value: ' '
6630.137512143:main thread    :         Entry(7f9a3f06e040): type 2, (FIELD), 
value: '3' 
6630.137516676:main thread    :         Entry(7f9a3f06e100): type 1, 
(CONSTANT), value: ' '
6630.137521199:main thread    :         Entry(7f9a3f06e1c0): type 2, (FIELD), 
value: '20' 
6630.137525811:main thread    :         Entry(7f9a3f06e280): type 1, 
(CONSTANT), value: ' '
6630.137530384:main thread    :         Entry(7f9a3f06e340): type 2, (FIELD), 
value: '21' 
6630.137534937:main thread    :         Entry(7f9a3f06e400): type 1, 
(CONSTANT), value: ' '
6630.137539495:main thread    :         Entry(7f9a3f06e4c0): type 2, (FIELD), 
value: '22' 
6630.137544049:main thread    :         Entry(7f9a3f06e580): type 1, 
(CONSTANT), value: ' '
6630.137548603:main thread    :         Entry(7f9a3f06e640): type 2, (FIELD), 
value: '19' 
6630.137553145:main thread    :         Entry(7f9a3f06e700): type 1, 
(CONSTANT), value: ' '
6630.137557723:main thread    :         Entry(7f9a3f06e7c0): type 2, (FIELD), 
value: '1' 
6630.137562249:main thread    :         Entry(7f9a3f06e880): type 1, 
(CONSTANT), value: '
'
6630.137566777:main thread    : Template: Name='RSYSLOG_FileFormat' 
6630.137569964:main thread    : Template: Name='RSYSLOG_TraditionalFileFormat' 
6630.137573054:main thread    : Template: Name=' WallFmt' 
6630.137576166:main thread    :         Entry(7f9a3f06e940): type 1, 
(CONSTANT), value: '
Message from syslogd@'
6630.137580794:main thread    :         Entry(7f9a3f06ea00): type 2, (FIELD), 
value: '3' 
6630.137585350:main thread    :         Entry(7f9a3f06eac0): type 1, 
(CONSTANT), value: ' at '
6630.137591769:main thread    :         Entry(7f9a3f06eb80): type 2, (FIELD), 
value: '16' 
6630.137596414:main thread    :         Entry(7f9a3f06ec40): type 1, 
(CONSTANT), value: ' ...
 '
6630.137601033:main thread    :         Entry(7f9a3f06ed00): type 2, (FIELD), 
value: '4' 
6630.137605649:main thread    :         Entry(7f9a3f06edc0): type 2, (FIELD), 
value: '1' 
6630.137610238:main thread    :         Entry(7f9a3f06ee80): type 1, 
(CONSTANT), value: '

'
6630.137614840:main thread    : Template: Name='RSYSLOG_ForwardFormat' 
6630.137618050:main thread    : Template: 
Name='RSYSLOG_TraditionalForwardFormat' 
6630.137621165:main thread    : Template: Name=' StdUsrMsgFmt' 
6630.137624353:main thread    :         Entry(7f9a3f06ef40): type 1, 
(CONSTANT), value: ' '
6630.137628943:main thread    :         Entry(7f9a3f06f0c0): type 2, (FIELD), 
value: '4' 
6630.137633473:main thread    :         Entry(7f9a3f06f180): type 2, (FIELD), 
value: '1' 
6630.137637955:main thread    :         Entry(7f9a3f06f240): type 1, 
(CONSTANT), value: '

'
6630.137642388:main thread    : Template: Name=' StdDBFmt' [SQL-Format (MySQL)] 
6630.137647121:main thread    :         Entry(7f9a3f06f300): type 1, 
(CONSTANT), value: 'insert into SystemEvents (Message, Facility, FromHost, 
Priority, DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values (''
6630.137651916:main thread    :         Entry(7f9a3f06f3c0): type 2, (FIELD), 
value: '1' 
6630.137656467:main thread    :         Entry(7f9a3f06f480): type 1, 
(CONSTANT), value: '', '
6630.137661042:main thread    :         Entry(7f9a3f06f540): type 2, (FIELD), 
value: '12' 
6630.137665596:main thread    :         Entry(7f9a3f06f600): type 1, 
(CONSTANT), value: ', ''
6630.137670127:main thread    :         Entry(7f9a3f06f6c0): type 2, (FIELD), 
value: '3' 
6630.137674685:main thread    :         Entry(7f9a3f06f780): type 1, 
(CONSTANT), value: '', '
6630.137679198:main thread    :         Entry(7f9a3f06f840): type 2, (FIELD), 
value: '14' 
6630.137683756:main thread    :         Entry(7f9a3f06f900): type 1, 
(CONSTANT), value: ', ''
6630.137688276:main thread    :         Entry(7f9a3f06f9c0): type 2, (FIELD), 
value: '2' [Format as MySQL-Date] [COMPLEX]
6630.137695750:main thread    :         Entry(7f9a3f06fa80): type 1, 
(CONSTANT), value: '', ''
6630.137700423:main thread    :         Entry(7f9a3f06fb40): type 2, (FIELD), 
value: '16' [Format as MySQL-Date] [COMPLEX]
6630.137707844:main thread    :         Entry(7f9a3f06fc00): type 1, 
(CONSTANT), value: '', '
6630.137712428:main thread    :         Entry(7f9a3f06fcc0): type 2, (FIELD), 
value: '11' 
6630.137717008:main thread    :         Entry(7f9a3f06fd80): type 1, 
(CONSTANT), value: ', ''
6630.137721544:main thread    :         Entry(7f9a3f06fe40): type 2, (FIELD), 
value: '4' 
6630.137726149:main thread    :         Entry(7f9a3f06ff00): type 1, 
(CONSTANT), value: '')'
6630.137730810:main thread    : Template: Name='RSYSLOG_SysklogdFileFormat' 
6630.137733998:main thread    :         Entry(7f9a3f06ffc0): type 2, (FIELD), 
value: '2' 
6630.137738557:main thread    :         Entry(7f9a3f070080): type 1, 
(CONSTANT), value: ' '
6630.137743061:main thread    :         Entry(7f9a3f070140): type 2, (FIELD), 
value: '3' 
6630.137747700:main thread    :         Entry(7f9a3f070200): type 1, 
(CONSTANT), value: ' '
6630.137752285:main thread    :         Entry(7f9a3f0702c0): type 2, (FIELD), 
value: '4' 
6630.137756968:main thread    :         Entry(7f9a3f070380): type 2, (FIELD), 
value: '1' [SP iff no first SP] [COMPLEX]
6630.137764305:main thread    :         Entry(7f9a3f070440): type 2, (FIELD), 
value: '1' 
6630.137768938:main thread    :         Entry(7f9a3f070500): type 1, 
(CONSTANT), value: '
'
6630.137773529:main thread    : Template: Name=' StdPgSQLFmt' [SQL-Format 
(standard SQL)] 
6630.137778171:main thread    :         Entry(7f9a3f0705c0): type 1, 
(CONSTANT), value: 'insert into SystemEvents (Message, Facility, FromHost, 
Priority, DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values (''
6630.137783016:main thread    :         Entry(7f9a3f070680): type 2, (FIELD), 
value: '1' 
6630.137787560:main thread    :         Entry(7f9a3f070740): type 1, 
(CONSTANT), value: '', '
6630.137792187:main thread    :         Entry(7f9a3f070800): type 2, (FIELD), 
value: '12' 
6630.137798044:main thread    :         Entry(7f9a3f0708c0): type 1, 
(CONSTANT), value: ', ''
6630.137802860:main thread    :         Entry(7f9a3f070980): type 2, (FIELD), 
value: '3' 
6630.137807460:main thread    :         Entry(7f9a3f070a40): type 1, 
(CONSTANT), value: '', '
6630.137812002:main thread    :         Entry(7f9a3f070b00): type 2, (FIELD), 
value: '14' 
6630.137816518:main thread    :         Entry(7f9a3f070bc0): type 1, 
(CONSTANT), value: ', ''
6630.137821075:main thread    :         Entry(7f9a3f070c80): type 2, (FIELD), 
value: '2' [Format as PgSQL-Date] [COMPLEX]
6630.137828542:main thread    :         Entry(7f9a3f070d40): type 1, 
(CONSTANT), value: '', ''
6630.137833143:main thread    :         Entry(7f9a3f070e00): type 2, (FIELD), 
value: '16' [Format as PgSQL-Date] [COMPLEX]
6630.137840449:main thread    :         Entry(7f9a3f070ec0): type 1, 
(CONSTANT), value: '', '
6630.137845004:main thread    :         Entry(7f9a3f070f80): type 2, (FIELD), 
value: '11' 
6630.137849548:main thread    :         Entry(7f9a3f071040): type 1, 
(CONSTANT), value: ', ''
6630.137854072:main thread    :         Entry(7f9a3f071100): type 2, (FIELD), 
value: '4' 
6630.137858600:main thread    :         Entry(7f9a3f0711c0): type 1, 
(CONSTANT), value: '')'
6630.137863042:main thread    : Template: Name=' StdJSONFmt' 
6630.137866295:main thread    :         Entry(7f9a3f071280): type 1, 
(CONSTANT), value: '{"message":"'
6630.137870877:main thread    :         Entry(7f9a3f071340): type 2, (FIELD), 
value: '1' [format as JSON] [COMPLEX]
6630.137878384:main thread    :         Entry(7f9a3f071400): type 1, 
(CONSTANT), value: '","fromhost":"'
6630.137883016:main thread    :         Entry(7f9a3f0714c0): type 2, (FIELD), 
value: '3' [format as JSON] [COMPLEX]
6630.137890354:main thread    :         Entry(7f9a3f071580): type 1, 
(CONSTANT), value: '","facility":"'
6630.137894971:main thread    :         Entry(7f9a3f071640): type 2, (FIELD), 
value: '13' 
6630.137899576:main thread    :         Entry(7f9a3f071700): type 1, 
(CONSTANT), value: '","priority":"'
6630.137904184:main thread    :         Entry(7f9a3f0717c0): type 2, (FIELD), 
value: '15' 
6630.137908697:main thread    :         Entry(7f9a3f071880): type 1, 
(CONSTANT), value: '","timereported":"'
6630.137913292:main thread    :         Entry(7f9a3f071940): type 2, (FIELD), 
value: '2' [Format as RFC3339-Date] [COMPLEX]
6630.137920759:main thread    :         Entry(7f9a3f071a00): type 1, 
(CONSTANT), value: '","timegenerated":"'
6630.137925383:main thread    :         Entry(7f9a3f071ac0): type 2, (FIELD), 
value: '16' [Format as RFC3339-Date] [COMPLEX]
6630.137932776:main thread    :         Entry(7f9a3f071b80): type 1, 
(CONSTANT), value: '"}'
6630.137937322:main thread    : Template: 
Name='RSYSLOG_omudpspoofDfltSourceTpl' 
6630.137940500:main thread    :         Entry(7f9a3f071c40): type 2, (FIELD), 
value: '8' 
6630.137944993:main thread    : Template: Name='startupfile' 
6630.137948142:main thread    :         Entry(7f9a3f071f40): type 1, 
(CONSTANT), value: 'rsyslogd.started'
6630.137952721:main thread    : Template: Name='outfmt' 
6630.137955878:main thread    :         Entry(7f9a3f086300): type 2, (FIELD), 
value: '1' [COMPLEX]
6630.137961848:main thread    :         Entry(7f9a3f0863c0): type 1, 
(CONSTANT), value: '
'
6630.137966497:main thread    : Main queue size 100000 messages.
6630.137968519:main thread    : Main queue worker threads: 2, wThread shutdown: 
60000, Perists every 0 updates.
6630.137970539:main thread    : Main queue timeouts: shutdown: 1500, action 
completion shutdown: 1000, enq: 2000
6630.137972566:main thread    : Main queue watermarks: high: 80000, low: 20000, 
discard: 98000, discard-severity: 8
6630.137974469:main thread    : Main queue save on shutdown 1, max disk space 
allowed 0
6630.137976287:main thread    : Work Directory: ''.
6630.137978114:main thread    : Modules used in this configuration:
6630.137979910:main thread    :     builtin:omfile
6630.137981686:main thread    :     builtin:ompipe
6630.137983420:main thread    :     builtin-shell
6630.137985161:main thread    :     builtin:omdiscard
6630.137986849:main thread    :     builtin:omfwd
6630.137988553:main thread    :     builtin:omusrmsg
6630.137990239:main thread    :     builtin:pmrfc5424
6630.137991941:main thread    :     builtin:pmrfc3164
6630.137995428:main thread    :     builtin:smfile
6630.137997366:main thread    :     builtin:smtradfile
6630.137999138:main thread    :     builtin:smfwd
6630.138000886:main thread    :     builtin:smtradfwd
6630.138002681:main thread    :     ../plugins/imdiag/.libs/imdiag
6630.138004589:main thread    :     ../plugins/imuxsock/.libs/imuxsock
6630.138006626:main thread    : GenerateLocalHostName uses 'vm-gentoo-x64'
6630.138009503:main thread    : ratelimit:rsyslogd[dflt]:new 
ratelimiter:bReduceRepeatMsgs 0
6630.138012056:main thread    : ratelimit:rsyslogd[internal_messages]:new 
ratelimiter:bReduceRepeatMsgs 0
6630.138014314:main thread    : rsyslogd: checking if startup is ok, pidfile 
'rsyslog.pid'.
6630.138020784:main thread    : telling modules to activate config (before 
dropping privs) 0x7f9a3f05e180
6630.138023592:main thread    : pre priv drop activating config 0x7f9a3f05e180 
for module ../plugins/imuxsock/.libs/imuxsock
6630.138025962:main thread    : imuxsock: allocating memory for 1 listeners
6630.138028509:main thread    : ratelimit:imuxsock:new 
ratelimiter:bReduceRepeatMsgs 0
6630.138049274:main thread    : imuxsock: Opened UNIX socket 'testbench_socket' 
(fd 4).
6630.138052043:main thread    : telling modules to activate config 
0x7f9a3f05e180
6630.138054126:main thread    : activating config 0x7f9a3f05e180 for module 
builtin:omfile
6630.138056046:main thread    : activating config 0x7f9a3f05e180 for module 
builtin:ompipe
6630.138058028:main thread    : activating config 0x7f9a3f05e180 for module 
builtin:omfwd
6630.138060051:main thread    : activating config 0x7f9a3f05e180 for module 
../plugins/imuxsock/.libs/imuxsock
6630.138062724:main thread    : iterateAllActions calling into action 
0x7f9a3f076100
6630.138064847:main thread    : action 1 queue: starting queue
6630.138069484:main thread    : action 1 queue: params: type 3, enq-only 0, 
disk assisted 0, spoolDir '', maxFileSz 1048576, maxQSize 1000, lqsize 0, 
pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16, high 
wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f. wrkr 1000
6630.138071968:main thread    : Action builtin:omfile[0x7f9a3f076100]: queue 
0x7f9a3f07a280 started
6630.138073865:main thread    : iterateAllActions calling into action 
0x7f9a3f076200
6630.138075585:main thread    : action 2 queue: starting queue
6630.138078435:main thread    : action 2 queue: params: type 3, enq-only 0, 
disk assisted 0, spoolDir '', maxFileSz 1048576, maxQSize 1000, lqsize 0, 
pqsize 0, child 0, full delay 970, light delay 700, deq batch size 16, high 
wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f. wrkr 1000
6630.138080537:main thread    : Action builtin:omfile[0x7f9a3f076200]: queue 
0x7f9a3f07a600 started
6630.138082813:main thread    : Activating Ruleset Queue[(nil)] for Ruleset 
RSYSLOG_DefaultRuleset
6630.138084904:main thread    : activateMainQueue: mainq cnf obj ptr is (nil)
6630.138087336:main thread    : main Q: starting queue
6630.138090547:main thread    : main Q: is NOT disk-assisted
6630.138093641:main thread    : main Q: params: type 0, enq-only 0, disk 
assisted 0, spoolDir '', maxFileSz 1048576, maxQSize 100000, lqsize 0, pqsize 
0, child 0, full delay 97000, light delay 70000, deq batch size 256, high 
wtrmrk 80000, low wtrmrk 20000, discardmrk 98000, max wrkr 2, min msgs f. wrkr 
40000
6630.138097436:main thread    : main Q:Reg: finalizing construction of worker 
thread pool (numworkerThreads 2)
6630.138100410:main thread    : main Q:Reg/w0: finalizing construction of 
worker instance data (for 2 actions)
6630.138103982:main thread    : main Q:Reg/w1: finalizing construction of 
worker instance data (for 2 actions)
6630.138106442:main thread    : main Q: queue finished initialization
6630.138109620:main thread    : Main processing queue is initialized and running
6630.138112221:main thread    : running module ../plugins/imdiag/.libs/imdiag 
with config 0x7f9a3f069440, term mode: cooperative/SIGTTIN
6630.138151602:main thread    : running module 
../plugins/imuxsock/.libs/imuxsock with config 0x7f9a3f069fe0, term mode: 
cooperative/SIGTTIN
6630.138183163:main thread    : configuration 0x7f9a3f05e180 activated
6630.138193329:7f9a3e7e5700: thread created, tid 33173, name 
'in:../plugins/imdiag/.l'
6630.138203852:7f9a3e7e5700: set thread name to 'in:../plugins/imdiag/.l'
6630.138551497:imdiag.c       : caller requested object 'nsd_ptcp', not found 
(iRet -3003)
6630.138562419:imdiag.c       : Requested to load module 'lmnsd_ptcp'
6630.138565940:imdiag.c       : loading module '../runtime/.libs/lmnsd_ptcp.so'
6630.138573218:main thread    : main Q: qqueueAdd: entry added, size now log 1, 
phys 1 entries
6630.138593418:main thread    : main Q:Reg: high activity - starting 1 
additional worker thread(s).
6630.138657319:7f9a3dfe4700: thread created, tid 33174, name 'in:imuxsock'
6630.138668310:7f9a3dfe4700: set thread name to 'in:imuxsock'
6630.139271449:imuxsock.c     : --------imuxsock calling select, active file 
descriptors (max 4): 4 
6630.139295278:main thread    : main Q:Reg: started with state 0, num workers 
now 1
6630.139313317:main thread    : main Q: EnqueueMsg advised worker start
6630.139319090:main thread    : rsyslogd: writing pidfile 'rsyslog.pid'.
6630.139347105:7f9a3cfff700: thread created, tid 33175, name 'rs:main Q:Reg'
6630.139901537:main Q:Reg/w0  : wti 0x7f9a3f02c3e0: worker starting
6630.139908136:main Q:Reg/w0  : DeleteProcessedBatch: we deleted 0 objects and 
enqueued 0 objects
6630.139910720:main Q:Reg/w0  : doDeleteBatch: delete batch from store, new 
sizes: log 1, phys 1
6630.139916209:main Q:Reg/w0  : processBATCH: batch of 1 elements must be 
processed
6630.139919129:main Q:Reg/w0  : processBATCH: next msg 0:  [origin 
software="rsyslogd" swVersion="8.8.0" x-pid="33170" 
x-info="http://www.rsyslog.com";] start
6630.139921905:main Q:Reg/w0  :     PROPFILT
6630.139926979:main Q:Reg/w0  :         Property.: 'syslogtag'
6630.139943416:main Q:Reg/w0  :         Operation: 'contains'
6630.139951937:main Q:Reg/w0  :         Value....: 'rsyslogd'
6630.139958033:main Q:Reg/w0  : Filter: check for property 'syslogtag' (value 
'rsyslogd:') contains 'rsyslogd': TRUE
6630.139961897:main Q:Reg/w0  : PROPFILT condition result is 1
6630.139963898:main Q:Reg/w0  :     ACTION 0 [builtin:omfile:?startupfile]
6630.139969176:main Q:Reg/w0  : executing action 0
6630.139981153:main Q:Reg/w0  : Called action, logging to builtin:omfile
6630.139990462:main Q:Reg/w0  : action 0 is transactional - executing in commit 
phase
6630.139993305:main Q:Reg/w0  : wti 0x7f9a3f02c3e0: we need to create a new 
action worker instance for action 0
6630.139997482:main Q:Reg/w0  : Action 0 transitioned to state: itx
6630.139999989:main Q:Reg/w0  :     PRIFILT '*.notice'
6630.140004998:main Q:Reg/w0  :     pmask: 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
6630.140073305:main Q:Reg/w0  : PRIFILT condition result is 0
6630.140084690:main Q:Reg/w0  : END batch execution phase, entering to commit 
phase
6630.140088766:main Q:Reg/w0  : actionCommitAll: action 0, state 1, nbr to 
commit 1 isTransactional 1
6630.140091274:main Q:Reg/w0  : doTransaction: have commitTransaction IF, using 
that, pWrkrInfo 0x7f9a3f0131e0
6630.140093482:main Q:Reg/w0  : entering actionCallCommitTransaction(), state: 
itx, actionNbr 0, nMsgs 1
6630.140095944:main Q:Reg/w0  : omfile: file to log to: rsyslogd.started
6630.140107759:main thread    : rsyslogd: initialization completed, 
transitioning to regular run mode
6630.140126575:main Q:Reg/w0  : file stream rsyslogd.started params: flush 
interval 0, async write 0
6630.140131060:main Q:Reg/w0  : Added new entry 0 for file cache, file 
'rsyslogd.started'.
6630.140133786:main Q:Reg/w0  : omfile: write to stream, pData->pStrm 
0x7f9a3bc22080, lenBuf 156, strt data 2015-03-03T19:17:10.138188+01:00 
vm-gentoo-x64 rsyslogd: [origin software="rsyslogd" swVersion="8.8.0" 
x-pid="33170" x-info="htt
6630.140137350:main Q:Reg/w0  : strm 0x7f9a3bc22080: file -1(rsyslogd.started) 
flush, buflen 156
6630.140140067:main Q:Reg/w0  : strmPhysWrite, stream 0x7f9a3bc22080, len 156
6630.140144632:main Q:Reg/w0  : file './rsyslogd.started' opened as #5 with 
mode 420
6630.140154657:main Q:Reg/w0  : strm 0x7f9a3bc22080: opened file 
'./rsyslogd.started' for WRITE as 5
6630.140168067:main Q:Reg/w0  : strm 0x7f9a3bc22080: file 5 write wrote 156 
bytes
6630.140170934:main Q:Reg/w0  : Action 0 transitioned to state: rdy
6630.140176210:main Q:Reg/w0  : Action 0 transitioned to state: itx
6630.140179083:main Q:Reg/w0  : Action 0 transitioned to state: rdy
6630.140181209:main Q:Reg/w0  : actionCommit, in retry loop, iRet 0
6630.140183237:main Q:Reg/w0  : processBATCH: batch of 1 elements has been 
processed
6630.140188164:main Q:Reg/w0  : regular consumer finished, iret=0, szlog 0 sz 
phys 1
6630.140192685:main Q:Reg/w0  : DeleteProcessedBatch: we deleted 1 objects and 
enqueued 0 objects
6630.140195148:main Q:Reg/w0  : doDeleteBatch: delete batch from store, new 
sizes: log 0, phys 0
6630.140200210:main Q:Reg/w0  : regular consumer finished, iret=4, szlog 0 sz 
phys 0
6630.140203128:main Q:Reg/w0  : main Q:Reg/w0: worker IDLE, waiting for work.
6630.140210407:imdiag.c       : source file nsd_ptcp.c requested reference for 
module 'lmnetstrms', reference count now 4
6630.140227452:imdiag.c       : module lmnsd_ptcp of type 2 being loaded 
(keepType=0).
6630.140230616:imdiag.c       : entry point 'isCompatibleWithFeature' not 
present in module
6630.140232679:imdiag.c       : entry point 'setModCnf' not present in module
6630.140234680:imdiag.c       : entry point 'getModCnfName' not present in 
module
6630.140236623:imdiag.c       : entry point 'beginCnfLoad' not present in module
6630.140239459:imdiag.c       : source file netstrms.c requested reference for 
module 'lmnsd_ptcp', reference count now 1
6630.140242869:imdiag.c       : creating tcp listen socket on port 13500
6630.140400842:imdiag.c       : Allocating buffer for 20 TCP sessions.
6630.140729397:imdiag.c       : nsdpoll_ptcp uses epoll_create1()
6630.140736798:imdiag.c       : tcpsrv uses epoll() interface, nsdpoll driver 
found
6630.140739305:imdiag.c       : Trying to add listener 0, pUsr=0x7f9a3d0270c0
6630.140741726:imdiag.c       : adding nsdpoll entry 0/0x7f9a3d0270c0, sock 6
6630.140746947:imdiag.c       : Added listener 0
6630.140749308:imdiag.c       : Trying to add listener 1, pUsr=0x7f9a3d0270c0
6630.140751434:imdiag.c       : adding nsdpoll entry 1/0x7f9a3d0270c0, sock 7
6630.140754071:imdiag.c       : Added listener 1
6630.140756321:imdiag.c       : doing epoll_wait for max 128 events
6630.247261250:imuxsock.c     : Message from UNIX socket: #4
6630.247306686:imuxsock.c     : main Q: qqueueAdd: entry added, size now log 1, 
phys 1 entries
6630.247356565:imuxsock.c     : main Q: EnqueueMsg advised worker start
6630.247369694:imuxsock.c     : --------imuxsock calling select, active file 
descriptors (max 4): 4 
6630.247397728:main Q:Reg/w0  : wti 0x7f9a3f02c3e0: worker awoke from idle 
processing
6630.247419751:main Q:Reg/w0  : DeleteProcessedBatch: we deleted 0 objects and 
enqueued 0 objects
6630.247428130:main Q:Reg/w0  : doDeleteBatch: delete batch from store, new 
sizes: log 1, phys 1
6630.247437752:main Q:Reg/w0  : processBATCH: batch of 1 elements must be 
processed
6630.247443933:main Q:Reg/w0  : processBATCH: next msg 0: <5>Mar  3 19:17:10 
vm-gentoo-x64 root: test
6630.247450378:main Q:Reg/w0  :     PROPFILT
6630.247463160:main Q:Reg/w0  :         Property.: 'syslogtag'
6630.247476255:main Q:Reg/w0  :         Operation: 'contains'
6630.247492114:main Q:Reg/w0  :         Value....: 'rsyslogd'
6630.247507307:main Q:Reg/w0  : Filter: check for property 'syslogtag' (value 
'vm-gentoo-x64') contains 'rsyslogd': FALSE
6630.247517094:main Q:Reg/w0  : PROPFILT condition result is 0
6630.247521914:main Q:Reg/w0  :     PRIFILT '*.notice'
6630.247534161:main Q:Reg/w0  :     pmask: 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
6630.247645496:main Q:Reg/w0  : PRIFILT condition result is 1
6630.247650305:main Q:Reg/w0  :     ACTION 1 
[builtin:omfile:./rsyslog.out.log;outfmt]
6630.247663650:main Q:Reg/w0  : executing action 1
6630.247669222:main Q:Reg/w0  : Called action, logging to builtin:omfile
6630.247691420:main Q:Reg/w0  : action 1 is transactional - executing in commit 
phase
6630.247698287:main Q:Reg/w0  : wti 0x7f9a3f02c3e0: we need to create a new 
action worker instance for action 1
6630.247705987:main Q:Reg/w0  : Action 1 transitioned to state: itx
6630.247711702:main Q:Reg/w0  : END batch execution phase, entering to commit 
phase
6630.247717631:main Q:Reg/w0  : actionCommitAll: action 0, state 0, nbr to 
commit 0 isTransactional 1
6630.247723416:main Q:Reg/w0  : actionCommitAll: action 1, state 1, nbr to 
commit 0 isTransactional 1
6630.247728609:main Q:Reg/w0  : doTransaction: have commitTransaction IF, using 
that, pWrkrInfo 0x7f9a3f013250
6630.247734012:main Q:Reg/w0  : entering actionCallCommitTransaction(), state: 
itx, actionNbr 1, nMsgs 1
6630.247793869:main Q:Reg/w0  : file stream rsyslog.out.log params: flush 
interval 0, async write 0
6630.247804610:main Q:Reg/w0  : omfile: write to stream, pData->pStrm 
0x7f9a3f056580, lenBuf 12, strt data  root: test

6630.247813123:main Q:Reg/w0  : strm 0x7f9a3f056580: file -1(rsyslog.out.log) 
flush, buflen 12
6630.247819571:main Q:Reg/w0  : strmPhysWrite, stream 0x7f9a3f056580, len 12
6630.247830047:main Q:Reg/w0  : file './rsyslog.out.log' opened as #9 with mode 
420
6630.247840666:main Q:Reg/w0  : strm 0x7f9a3f056580: opened file 
'./rsyslog.out.log' for WRITE as 9
6630.247860286:main Q:Reg/w0  : strm 0x7f9a3f056580: file 9 write wrote 12 bytes
6630.247867149:main Q:Reg/w0  : Action 1 transitioned to state: rdy
6630.247873307:main Q:Reg/w0  : Action 1 transitioned to state: itx
6630.247878946:main Q:Reg/w0  : Action 1 transitioned to state: rdy
6630.247884408:main Q:Reg/w0  : actionCommit, in retry loop, iRet 0
6630.247889553:main Q:Reg/w0  : processBATCH: batch of 1 elements has been 
processed
6630.247895297:main Q:Reg/w0  : regular consumer finished, iret=0, szlog 0 sz 
phys 1
6630.247902818:main Q:Reg/w0  : DeleteProcessedBatch: we deleted 1 objects and 
enqueued 0 objects
6630.247908332:main Q:Reg/w0  : doDeleteBatch: delete batch from store, new 
sizes: log 0, phys 0
6630.247914097:main Q:Reg/w0  : regular consumer finished, iret=4, szlog 0 sz 
phys 0
6630.247919489:main Q:Reg/w0  : main Q:Reg/w0: worker IDLE, waiting for work.
6630.359327871:imdiag.c       : epoll returned 1 entries
6630.359357633:imdiag.c       : epoll push ppusr[0]: 0x7f9a3d0270c0
6630.359365932:imdiag.c       : tcpsrv: ready to process 1 event entries
6630.359371732:imdiag.c       : tcpsrv: processing item 0, pUsr 0x7f9a3d0270c0, 
bAbortConn
6630.359377280:imdiag.c       : New connect on NSD 0x7f9a3d03f100.
6630.359401217:imdiag.c       : dnscache: entry (nil) found
6630.359807510:imdiag.c       : adding nsdpoll entry 0/0x7f9a3d0321d0, sock 10
6630.359828183:imdiag.c       : New session created with NSD 0x7f9a3d0321d0.
6630.359835131:imdiag.c       : doing epoll_wait for max 128 events
6630.359842202:imdiag.c       : epoll returned 1 entries
6630.359847789:imdiag.c       : epoll push ppusr[0]: 0x7f9a3d0321d0
6630.359852926:imdiag.c       : tcpsrv: ready to process 1 event entries
6630.359858370:imdiag.c       : tcpsrv: processing item 0, pUsr 0x7f9a3d0321d0, 
bAbortConn
6630.359875449:imdiag.c       : netstream 0x7f9a3d03f2c0 with new data
6630.359903126:imdiag.c       : imdiag received command 'waitmainqueueempty'
6631.114277727:imdiag.c       : imdiag: mainqueue empty
6631.114317370:imdiag.c       : doing epoll_wait for max 128 events
6631.114632839:imdiag.c       : epoll returned 1 entries
6631.114653767:imdiag.c       : epoll push ppusr[0]: 0x7f9a3d0321d0
6631.114661215:imdiag.c       : tcpsrv: ready to process 1 event entries
6631.114667025:imdiag.c       : tcpsrv: processing item 0, pUsr 0x7f9a3d0321d0, 
bAbortConn
6631.114672781:imdiag.c       : netstream 0x7f9a3d03f2c0 with new data
6631.114683756:imdiag.c       : removing nsdpoll entry 0/0x7f9a3d0321d0, sock 10
6631.114757340:imdiag.c       : doing epoll_wait for max 128 events
6632.122139693:main thread    : DoDie called.
6632.122181955:main thread    : exiting on signal 15
6632.122187851:main thread    : Terminating input threads...
6632.122208610:main thread    : request term via SIGTTIN for input thread 
'../plugins/imdiag/.libs/imdiag' 0x3e7e5700
6632.122343466:imdiag.c       : removing nsdpoll entry 0/0x7f9a3d0270c0, sock 6
6632.122369415:imdiag.c       : removing nsdpoll entry 1/0x7f9a3d0270c0, sock 7
6632.122380893:imdiag.c       : thrdStarter: usrThrdMain 
../plugins/imdiag/.libs/imdiag - 0x7f9a3e7e5700 returned with iRet 0, exiting 
now.
6632.122478602:main thread    : input thread term: thread 
../plugins/imdiag/.libs/imdiag returned normally and is terminated
6632.122500081:main thread    : non-cancel input thread termination succeeded 
for thread ../plugins/imdiag/.libs/imdiag 0x3e7e5700
6632.122860126:imdiag.c       : destructor for debug call stack 0x7f9a3d00e000 
called
6632.123009731:main thread    : request term via SIGTTIN for input thread 
'imuxsock' 0x3dfe4700
6632.123179723:imuxsock.c     : thrdStarter: usrThrdMain imuxsock - 
0x7f9a3dfe4700 returned with iRet 0, exiting now.
6632.123289814:main thread    : input thread term: thread imuxsock returned 
normally and is terminated
6632.123340412:main thread    : non-cancel input thread termination succeeded 
for thread imuxsock 0x3dfe4700
6632.123528580:imuxsock.c     : destructor for debug call stack 0x7f9a3c00e000 
called
6632.123673614:main thread    : imuxsock: unlinking unix socket file[1] 
testbench_socket
6632.123747853:main thread    : main Q: qqueueAdd: entry added, size now log 1, 
phys 1 entries
6632.123815825:main thread    : main Q: EnqueueMsg advised worker start
6632.123865370:main Q:Reg/w0  : wti 0x7f9a3f02c3e0: worker awoke from idle 
processing
6632.123887786:main Q:Reg/w0  : DeleteProcessedBatch: we deleted 0 objects and 
enqueued 0 objects
6632.123894129:main Q:Reg/w0  : doDeleteBatch: delete batch from store, new 
sizes: log 1, phys 1
6632.123903291:main Q:Reg/w0  : processBATCH: batch of 1 elements must be 
processed
6632.123909503:main Q:Reg/w0  : processBATCH: next msg 0:  [origin 
software="rsyslogd" swVersion="8.8.0" x-pid="33170" 
x-info="http://www.rsyslog.com";] exiting on signal 15.
6632.123915970:main Q:Reg/w0  :     PROPFILT
6632.123928046:main Q:Reg/w0  :         Property.: 'syslogtag'
6632.123940847:main Q:Reg/w0  :         Operation: 'contains'
6632.123956512:main Q:Reg/w0  :         Value....: 'rsyslogd'
6632.123971438:main Q:Reg/w0  : Filter: check for property 'syslogtag' (value 
'rsyslogd:') contains 'rsyslogd': TRUE
6632.123981065:main Q:Reg/w0  : PROPFILT condition result is 1
6632.123985768:main Q:Reg/w0  :     ACTION 0 [builtin:omfile:?startupfile]
6632.123998652:main Q:Reg/w0  : executing action 0
6632.124004383:main Q:Reg/w0  : Called action, logging to builtin:omfile
6632.124013989:main Q:Reg/w0  : action 0 is transactional - executing in commit 
phase
6632.124020638:main Q:Reg/w0  : Action 0 transitioned to state: itx
6632.124026103:main Q:Reg/w0  :     PRIFILT '*.notice'
6632.124038217:main Q:Reg/w0  :     pmask: 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
6632.124174267:main thread    : Terminating main queue...
6632.124228622:main thread    : main Q: initiating worker thread shutdown 
sequence
6632.124239231:main thread    : main Q: trying shutdown of regular workers
6632.124289545:main Q:Reg/w0  : 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 3F 
6632.124393929:main thread    : sent SIGTTIN to worker thread 0x3cfff700
6632.124451741:main thread    : main Q:Reg: waiting 1499ms on worker thread 
termination, 1 still running
6632.124503904:main Q:Reg/w0  : 3F 3F 
6632.124536687:main Q:Reg/w0  : PRIFILT condition result is 0
6632.124541970:main Q:Reg/w0  : END batch execution phase, entering to commit 
phase
6632.124547915:main Q:Reg/w0  : actionCommitAll: action 0, state 1, nbr to 
commit 1 isTransactional 1
6632.124554116:main Q:Reg/w0  : doTransaction: have commitTransaction IF, using 
that, pWrkrInfo 0x7f9a3f0131e0
6632.124559712:main Q:Reg/w0  : entering actionCallCommitTransaction(), state: 
itx, actionNbr 0, nMsgs 1
6632.124565946:main Q:Reg/w0  : omfile: file to log to: rsyslogd.started
6632.124573110:main Q:Reg/w0  : omfile: write to stream, pData->pStrm 
0x7f9a3bc22080, lenBuf 172, strt data 2015-03-03T19:17:12.123736+01:00 
vm-gentoo-x64 rsyslogd: [origin software="rsyslogd" swVersion="8.8.0" 
x-pid="33170" x-info="htt
6632.124590684:main Q:Reg/w0  : strm 0x7f9a3bc22080: file 5(rsyslogd.started) 
flush, buflen 172
6632.124597708:main Q:Reg/w0  : strmPhysWrite, stream 0x7f9a3bc22080, len 172
6632.124611331:main Q:Reg/w0  : strm 0x7f9a3bc22080: file 5 write wrote 172 
bytes
6632.124618104:main Q:Reg/w0  : Action 0 transitioned to state: rdy
6632.124624183:main Q:Reg/w0  : Action 0 transitioned to state: itx
6632.124629515:main Q:Reg/w0  : Action 0 transitioned to state: rdy
6632.124634738:main Q:Reg/w0  : actionCommit, in retry loop, iRet 0
6632.124639976:main Q:Reg/w0  : actionCommitAll: action 1, state 0, nbr to 
commit 0 isTransactional 1
6632.124644961:main Q:Reg/w0  : processBATCH: batch of 1 elements has been 
processed
6632.124650564:main Q:Reg/w0  : regular consumer finished, iret=0, szlog 0 sz 
phys 1
6632.124659223:main Q:Reg/w0  : DeleteProcessedBatch: we deleted 1 objects and 
enqueued 0 objects
6632.124664761:main Q:Reg/w0  : doDeleteBatch: delete batch from store, new 
sizes: log 0, phys 0
6632.124670978:main Q:Reg/w0  : regular consumer finished, iret=4, szlog 0 sz 
phys 0
6632.124676421:main Q:Reg/w0  : wti 0x7f9a3f02c3e0: terminating worker 
terminateRet=5, bInactivityTOOccured=0
6632.124681777:main Q:Reg/w0  : DDDD: wti 0x7f9a3f02c3e0: worker cleanup action 
instances
6632.124686968:main Q:Reg/w0  : wti 0x7f9a3f02c3e0, action 0, ptr 0x7f9a3bc1f058
6632.124693406:main Q:Reg/w0  : wti 0x7f9a3f02c3e0, action 1, ptr 0x7f9a3bc1f068
6632.124698713:main Q:Reg/w0  : wti 0x7f9a3f02c3e0: worker exiting
6632.124704375:main Q:Reg/w0  : main Q:Reg: Worker thread 7f9a3f02c3e0, 
terminated, num workers now 0
6632.124845446:main thread    : main Q: regular queue workers shut down.
6632.124867369:main thread    : main Q: checking to see if we need to cancel 
any worker threads of the primary queue
6632.124876117:main thread    : main Q: worker threads terminated, remaining 
queue size log 0, phys 0.
6632.124889688:main thread    : main Q: queue (type 0) will lose 0 messages, 
destroying...
6632.125138167:main Q:Reg/w0  : destructor for debug call stack 0x7f9a3bc0e000 
called
6632.125201330:main thread    : Terminating outputs...
6632.125236719:main thread    : destructing ruleset 0x7f9a3f064500, name 
0x7f9a3f034a00
6632.125247921:main thread    : Removing entry 0 for file 'rsyslogd.started' 
from dynaCache.
6632.125254272:main thread    : strm 0x7f9a3bc22080: file 5(rsyslogd.started) 
closing
6632.125260072:main thread    : strm 0x7f9a3bc22080: file 5(rsyslogd.started) 
flush, buflen 0 (no need to flush)
6632.125269337:main thread    : DDDD: strmCloseFile: 5
6632.125282456:main thread    : strm 0x7f9a3f056580: file 9(rsyslog.out.log) 
closing
6632.125312038:main thread    : strm 0x7f9a3f056580: file 9(rsyslog.out.log) 
flush, buflen 0 (no need to flush)
6632.125322417:main thread    : DDDD: strmCloseFile: 9
6632.125331850:main thread    : all primary multi-thread sources have been 
terminated - now doing aux cleanup...
6632.125337383:main thread    : destructing current config...
6632.125343267:main thread    : calling freeCnf(0x7f9a3f01b220) for module 
'builtin:omfile'
6632.125371357:main thread    : calling freeCnf(0x7f9a3f010230) for module 
'builtin:ompipe'
6632.125380765:main thread    : calling freeCnf(0x7f9a3f010260) for module 
'builtin:omfwd'
6632.125387175:main thread    : calling freeCnf(0x7f9a3f066840) for module 
'../plugins/imuxsock/.libs/imuxsock'
6632.125449018:main thread    : destructing parser 'rsyslog.rfc5424'
6632.125455716:main thread    : destructing parser 'rsyslog.rfc3164'
6632.125471873:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 5
6632.125478132:main thread    : Unloading module builtin:omfile
6632.125484269:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 5
6632.125489118:main thread    : Unloading module builtin:ompipe
6632.125494294:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 5
6632.125510150:main thread    : Unloading module builtin-shell
6632.125516494:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 5
6632.125521419:main thread    : Unloading module builtin:omdiscard
6632.125526710:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 5
6632.125531537:main thread    : Unloading module builtin:omfwd
6632.125540356:main thread    : file omfwd.c released module 'lmnet', reference 
count now 4
6632.125547075:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 4
6632.125552176:main thread    : Unloading module builtin:omusrmsg
6632.125557168:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 4
6632.125562000:main thread    : Unloading module builtin:pmrfc5424
6632.125567443:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 4
6632.125572138:main thread    : Unloading module builtin:pmrfc3164
6632.125577502:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 4
6632.125582159:main thread    : Unloading module builtin:smfile
6632.125587143:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 4
6632.125591800:main thread    : Unloading module builtin:smtradfile
6632.125596846:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 4
6632.125601420:main thread    : Unloading module builtin:smfwd
6632.125606213:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 4
6632.125610721:main thread    : Unloading module builtin:smtradfwd
6632.125615514:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 4
6632.125620251:main thread    : module lmnetstrms NOT unloaded because it still 
has a refcount of 4
6632.125624925:main thread    : module lmtcpsrv NOT unloaded because it still 
has a refcount of 2
6632.125629691:main thread    : Unloading module ../plugins/imdiag/.libs/imdiag
6632.125661433:main thread    : file netstrms.c released module 'lmnsd_ptcp', 
reference count now 0
6632.125668762:main thread    : module 'lmnsd_ptcp' has zero reference count, 
unloading...
6632.125673599:main thread    : Unloading module lmnsd_ptcp
6632.125682553:main thread    : file nsd_ptcp.c released module 'lmnetstrms', 
reference count now 3
6632.125799423:main thread    : file imdiag.c released module 'lmnet', 
reference count now 3
6632.125811017:main thread    : file imdiag.c released module 'lmnetstrms', 
reference count now 2
6632.125817526:main thread    : file imdiag.c released module 'lmtcpsrv', 
reference count now 1
6632.125823882:main thread    : file imdiag.c released module 'lmtcpsrv', 
reference count now 0
6632.125828944:main thread    : module 'lmtcpsrv' has zero reference count, 
unloading...
6632.125833661:main thread    : Unloading module lmtcpsrv
6632.126289108:main thread    : tcpsrv: info: worker 0 was called 0 times
6632.126546323:main thread    : tcpsrv: info: worker 1 was called 0 times
6632.126770795:main thread    : tcpsrv: info: worker 2 was called 0 times
6632.127135645:main thread    : tcpsrv: info: worker 3 was called 0 times
6632.127158119:main thread    : file tcpsrv.c released module 'lmnetstrms', 
reference count now 1
6632.127166458:main thread    : file tcpsrv.c released module 'lmnet', 
reference count now 2
6632.127174825:main thread    : file tcps_sess.c released module 'lmnetstrms', 
reference count now 0
6632.127180383:main thread    : module 'lmnetstrms' has zero reference count, 
unloading...
6632.127185481:main thread    : Unloading module lmnetstrms
6632.127263870:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 2
6632.127272147:main thread    : Unloading module 
../plugins/imuxsock/.libs/imuxsock
6632.127297985:main thread    : module lmnet NOT unloaded because it still has 
a refcount of 2
6632.127307745:main thread    : file conf.c released module 'lmnet', reference 
count now 1
6632.127317352:main thread    : rsyslog runtime de-initialized, current users 0
6632.127322626:main thread    : Clean shutdown completed, bye
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of 
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE 
THAT.

Reply via email to