Ok, just to clarify / summarise; it seems that if I have a client rsyslog that
logs to a remote rsyslog via TCP or RELP, on restarting the remote server, one
message is lost on reconnect. I've tried the standard 8.4 distro RPM version
and also I've built from git source - same issue. Here's the debug trace that
hopefully demonstrates the issue .. I've added a couple of output lines just to
clarify where the enqueue / dequeue is happening in relation to the disconnect
/ reconnect.
I'd be very grateful if someone could take a look, data going missing is pretty
critical for us ....
Here is the time-line summary from my debug statements;
====
0296.924460034:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD
0296.924590119:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
<remote rsyslog shut down here>
0304.004957866:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD AAA
0304.005094611:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
AAA
0305.888005537:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD BBB
0305.888165880:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
BBB <-- this is "lost"
0305.888236891:action 2 queue:Reg/w0: relp session 0x7fae8c0023e0 flagged as
broken, IO error
0305.888240810:action 2 queue:Reg/w0: error forwarding via relp, suspending
0308.064202433:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD CCC
0309.806979297:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD DDD
0310.863961543:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD
<remote server restarted here>
0315.901983039:action 2 queue:Reg/w0: relp session 0x7fae8c0023e0
reestablished, now resending 3 unacked frames
0315.902177647:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
CCC
Del from LL: HELLO WORLD DDD
0315.902185396:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
====
"HELLO WORLD BBB" appears in the local log file, but not in the remote log file.
My understanding is that with a LinkedList queue in place and using RELP as the
transfer protocol - this shouldn't happen ??
Full Debug session;
0289.266048093:main thread : rsyslogd 8.5.0 startup, module path '',
cwd:/usr/local/src/rsyslog
0289.266249739:main thread : caller requested object 'net', not found (iRet
-3003)
0289.266263185:main thread : Requested to load module 'lmnet'
0289.266270718:main thread : loading module '/usr/local/lib/rsyslog/lmnet.so'
0289.266363339:main thread : module lmnet of type 2 being loaded
(keepType=0).
0289.266372023:main thread : entry point 'isCompatibleWithFeature' not
present in module
0289.266375706:main thread : entry point 'setModCnf' not present in module
0289.266379389:main thread : entry point 'getModCnfName' not present in
module
0289.266382705:main thread : entry point 'beginCnfLoad' not present in module
0289.266387693:main thread : source file conf.c requested reference for
module 'lmnet', reference count now 1
0289.266409090:main thread : rsyslog runtime initialized, version 8.5.0,
current users 1
0289.266450687:main thread : source file rsyslogd.c requested reference for
module 'lmnet', reference count now 2
0289.266469186:main thread : source file syslogd.c requested reference for
module 'lmnet', reference count now 3
0289.266485576:main thread : GenerateLocalHostName uses 'server'
0289.266492471:main thread : deque option n, optarg ''
0289.266553505:main thread : omfile: using transactional output interface.
0289.266585726:main thread : module builtin:omfile of type 1 being loaded
(keepType=0).
0289.266592289:main thread : module config name is 'omfile'
0289.266596330:main thread : module builtin:omfile supports rsyslog v6
config interface
0289.266602225:main thread : entry point 'activateCnfPrePrivDrop' not
present in module
0289.266607985:main thread : entry point 'SetShutdownImmdtPtr' not present
in module
0289.266612025:main thread : entry point 'doAction' not present in module
0289.266616346:main thread : entry point 'endTransaction' not present in
module
0289.266654880:main thread : module builtin:ompipe of type 1 being loaded
(keepType=0).
0289.266666634:main thread : module config name is 'ompipe'
0289.266670816:main thread : module builtin:ompipe supports rsyslog v6
config interface
0289.266676161:main thread : entry point 'activateCnfPrePrivDrop' not
present in module
0289.266681573:main thread : entry point 'SetShutdownImmdtPtr' not present
in module
0289.266685269:main thread : entry point 'beginTransaction' not present in
module
0289.266689228:main thread : entry point 'commitTransaction' not present in
module
0289.266692795:main thread : entry point 'endTransaction' not present in
module
0289.266701360:main thread : module builtin-shell of type 1 being loaded
(keepType=0).
0289.266705902:main thread : entry point 'setModCnf' not present in module
0289.266712224:main thread : entry point 'getModCnfName' not present in
module
0289.266718933:main thread : entry point 'beginCnfLoad' not present in module
0289.266726652:main thread : entry point 'doHUP' not present in module
0289.266733007:main thread : entry point 'SetShutdownImmdtPtr' not present
in module
0289.266739604:main thread : entry point 'beginTransaction' not present in
module
0289.266746335:main thread : entry point 'commitTransaction' not present in
module
0289.266752173:main thread : entry point 'endTransaction' not present in
module
0289.266756041:main thread : entry point 'newActInst' not present in module
0289.266763880:main thread : module builtin:omdiscard of type 1 being loaded
(keepType=0).
0289.266768351:main thread : entry point 'setModCnf' not present in module
0289.266772086:main thread : entry point 'getModCnfName' not present in
module
0289.266775650:main thread : entry point 'beginCnfLoad' not present in module
0289.266780390:main thread : entry point 'doHUP' not present in module
0289.266783979:main thread : entry point 'SetShutdownImmdtPtr' not present
in module
0289.266787467:main thread : entry point 'beginTransaction' not present in
module
0289.266790997:main thread : entry point 'commitTransaction' not present in
module
0289.266799579:main thread : entry point 'endTransaction' not present in
module
0289.266803484:main thread : entry point 'newActInst' not present in module
0289.266811372:main thread : source file omfwd.c requested reference for
module 'lmnet', reference count now 4
0289.266829070:main thread : module builtin:omfwd of type 1 being loaded
(keepType=0).
0289.266834855:main thread : module config name is 'omfwd'
0289.266838827:main thread : module builtin:omfwd supports rsyslog v6 config
interface
0289.266844070:main thread : entry point 'activateCnfPrePrivDrop' not
present in module
0289.266849166:main thread : entry point 'doHUP' not present in module
0289.266852690:main thread : entry point 'SetShutdownImmdtPtr' not present
in module
0289.266856594:main thread : entry point 'doAction' not present in module
0289.266860316:main thread : entry point 'endTransaction' not present in
module
0289.266867428:main thread : module builtin:omusrmsg of type 1 being loaded
(keepType=0).
0289.266871787:main thread : entry point 'setModCnf' not present in module
0289.266875567:main thread : module config name is 'omusrmsg'
0289.266879185:main thread : entry point 'beginCnfLoad' not present in module
0289.266883918:main thread : entry point 'doHUP' not present in module
0289.266887345:main thread : entry point 'SetShutdownImmdtPtr' not present
in module
0289.266890717:main thread : entry point 'beginTransaction' not present in
module
0289.266894279:main thread : entry point 'commitTransaction' not present in
module
0289.266897627:main thread : entry point 'endTransaction' not present in
module
0289.266906464:main thread : rfc5424 parser init called
0289.266910816:main thread : GetParserName addr 0x454980
0289.266914578:main thread : module builtin:pmrfc5424 of type 3 being loaded
(keepType=0).
0289.266918147:main thread : entry point 'setModCnf' not present in module
0289.266921382:main thread : entry point 'getModCnfName' not present in
module
0289.266924536:main thread : entry point 'beginCnfLoad' not present in module
0289.266927756:main thread : entry point 'parse2' not present in module
0289.266935261:main thread : DDDDD: added parser 'rsyslog.rfc5424' to list
0x6967e8
0289.266938649:main thread : Parser 'rsyslog.rfc5424' added to list of
available parsers.
0289.266945344:main thread : rfc3164 parser init called
0289.266950662:main thread : module builtin:pmrfc3164 of type 3 being loaded
(keepType=0).
0289.266954216:main thread : entry point 'setModCnf' not present in module
0289.266957548:main thread : entry point 'getModCnfName' not present in
module
0289.266960680:main thread : entry point 'beginCnfLoad' not present in module
0289.266963967:main thread : entry point 'parse2' not present in module
0289.266968125:main thread : DDDDD: added parser 'rsyslog.rfc3164' to list
0x6967e8
0289.266971274:main thread : Parser 'rsyslog.rfc3164' added to list of
available parsers.
0289.266975133:main thread : DDDDD: added parser 'rsyslog.rfc5424' to list
0x6967f0
0289.266978205:main thread : Parser 'rsyslog.rfc5424' added to default
parser set.
0289.266981520:main thread : DDDDD: added parser 'rsyslog.rfc3164' to list
0x6967f0
0289.266984511:main thread : Parser 'rsyslog.rfc3164' added to default
parser set.
0289.266989219:main thread : rsyslog standard file format strgen init
called, compiled with version 8.5.0
0289.266994033:main thread : module builtin:smfile of type 4 being loaded
(keepType=0).
0289.267071676:main thread : entry point 'isCompatibleWithFeature' not
present in module
0289.267141385:main thread : entry point 'setModCnf' not present in module
0289.267149818:main thread : entry point 'getModCnfName' not present in
module
0289.267153322:main thread : entry point 'beginCnfLoad' not present in module
0289.267160458:main thread : Strgen 'RSYSLOG_FileFormat' added to list of
available strgens.
0289.267171849:main thread : traditional file format strgen init called,
compiled with version 8.5.0
0289.267187145:main thread : module builtin:smtradfile of type 4 being
loaded (keepType=0).
0289.267193863:main thread : entry point 'isCompatibleWithFeature' not
present in module
0289.267199815:main thread : entry point 'setModCnf' not present in module
0289.267206388:main thread : entry point 'getModCnfName' not present in
module
0289.267212486:main thread : entry point 'beginCnfLoad' not present in module
0289.267217597:main thread : Strgen 'RSYSLOG_TraditionalFileFormat' added to
list of available strgens.
0289.267222427:main thread : rsyslog standard (network) forward format
strgen init called, compiled with version 8.5.0
0289.267226314:main thread : module builtin:smfwd of type 4 being loaded
(keepType=0).
0289.267229657:main thread : entry point 'isCompatibleWithFeature' not
present in module
0289.267232781:main thread : entry point 'setModCnf' not present in module
0289.267235907:main thread : entry point 'getModCnfName' not present in
module
0289.267238984:main thread : entry point 'beginCnfLoad' not present in module
0289.267242820:main thread : Strgen 'RSYSLOG_ForwardFormat' added to list of
available strgens.
0289.267246597:main thread : rsyslog traditional (network) forward format
strgen init called, compiled with version 8.5.0
0289.267250403:main thread : module builtin:smtradfwd of type 4 being loaded
(keepType=0).
0289.267253652:main thread : entry point 'isCompatibleWithFeature' not
present in module
0289.267256757:main thread : entry point 'setModCnf' not present in module
0289.267259857:main thread : entry point 'getModCnfName' not present in
module
0289.267262897:main thread : entry point 'beginCnfLoad' not present in module
0289.267267033:main thread : Strgen 'RSYSLOG_TraditionalForwardFormat' added
to list of available strgens.
0289.267270683:main thread : doing legacy config system init
0289.267334363:main thread : tplAddLine processing template
'RSYSLOG_DebugFormat'
0289.267376713:main thread : tplAddLine processing template
'RSYSLOG_SyslogProtocol23Format'
0289.267390547:main thread : tplAddLine processing template
'RSYSLOG_FileFormat'
0289.267395448:main thread : template bound to strgen 'RSYSLOG_FileFormat'
0289.267400494:main thread : tplAddLine processing template
'RSYSLOG_TraditionalFileFormat'
0289.267404801:main thread : template bound to strgen
'RSYSLOG_TraditionalFileFormat'
0289.267408410:main thread : tplAddLine processing template ' WallFmt'
0289.267417618:main thread : tplAddLine processing template
'RSYSLOG_ForwardFormat'
0289.267421970:main thread : template bound to strgen 'RSYSLOG_ForwardFormat'
0289.267425580:main thread : tplAddLine processing template
'RSYSLOG_TraditionalForwardFormat'
0289.267429330:main thread : template bound to strgen
'RSYSLOG_TraditionalForwardFormat'
0289.267432894:main thread : tplAddLine processing template ' StdUsrMsgFmt'
0289.267437771:main thread : tplAddLine processing template ' StdDBFmt'
0289.267456572:main thread : tplAddLine processing template
'RSYSLOG_SysklogdFileFormat'
0289.267464227:main thread : tplAddLine processing template ' StdPgSQLFmt'
0289.267475647:main thread : tplAddLine processing template ' StdJSONFmt'
0289.267488048:main thread : tplAddLine processing template
'RSYSLOG_omudpspoofDfltSourceTpl'
0289.267610297:main thread : config parser: pushed file /etc/rsyslog.conf on
top of stack
0289.267684171:main thread : cnf:global:cfsysline: $WorkDirectory
/var/lib/rsyslog
0289.267699612:main thread : doGetWord: get newval '/var/lib/rsyslog' (len
16), hdlr 0x410550
0289.267735448:main thread : cnf:global:obj: obj: 'module'
0289.267750178:main thread : nvlst 0x12b1fa0:
0289.267758061:main thread : name: 'load', value 'imfile'
0289.267770611:main thread : nvlstGetParam: name 'load', type 13,
valnode->bUsed 0
0289.267778855:main thread : modulesProcessCnf params:
0289.267785866:main thread : load: 'imfile'
0289.267796409:main thread : Requested to load module 'imfile'
0289.267806601:main thread : loading module
'/usr/local/lib/rsyslog/imfile.so'
0289.267881726:main thread : imfile: version 8.5.0 initializing
0289.267909169:main thread : module imfile of type 0 being loaded
(keepType=0).
0289.267916574:main thread : module config name is 'imfile'
0289.267920378:main thread : module imfile supports rsyslog v6 config
interface
0289.267925272:main thread : entry point 'activateCnfPrePrivDrop' not
present in module
0289.267932795:main thread : module (global) param blk for imfile:
0289.267936310:main thread : pollinginterval: (unset)
0289.267944075:main thread : mode: (unset)
0289.267966513:main thread : cnf:global:obj: obj: 'module'
0289.267973440:main thread : nvlst 0x12b1fd0:
0289.267976848:main thread : name: 'load', value 'imuxsock'
0289.267980649:main thread : nvlstGetParam: name 'load', type 13,
valnode->bUsed 0
0289.267984196:main thread : modulesProcessCnf params:
0289.267987246:main thread : load: 'imuxsock'
0289.267995557:main thread : Requested to load module 'imuxsock'
0289.267999639:main thread : loading module
'/usr/local/lib/rsyslog/imuxsock.so'
0289.268074968:main thread : imuxsock version 8.5.0 initializing
0289.268082793:main thread : rsyslog/glbl: using '127.0.0.1' as localhost IP
0289.268150777:main thread : module imuxsock of type 0 being loaded
(keepType=0).
0289.268158326:main thread : module config name is 'imuxsock'
0289.268162101:main thread : module imuxsock supports rsyslog v6 config
interface
0289.268172152:main thread : module (global) param blk for imuxsock:
0289.268176091:main thread : syssock.use: (unset)
0289.268184082:main thread : syssock.name: (unset)
0289.268191743:main thread : syssock.unlink: (unset)
0289.268200282:main thread : syssock.ignoretimestamp: (unset)
0289.268214891:main thread : syssock.ignoreownmessages: (unset)
0289.268229620:main thread : syssock.flowcontrol: (unset)
0289.268244055:main thread : syssock.usesystimestamp: (unset)
0289.268255303:main thread : syssock.annotate: (unset)
0289.268263162:main thread : syssock.parsetrusted: (unset)
0289.268270713:main thread : syssock.usepidfromsystem: (unset)
0289.268278271:main thread : syssock.ratelimit.interval: (unset)
0289.268285834:main thread : syssock.ratelimit.burst: (unset)
0289.268293269:main thread : syssock.ratelimit.severity: (unset)
0289.268313055:main thread : cnf:global:obj: obj: 'module'
0289.268319526:main thread : nvlst 0x12b1fa0:
0289.268323002:main thread : name: 'load', value 'imklog'
0289.268327106:main thread : nvlstGetParam: name 'load', type 13,
valnode->bUsed 0
0289.268330611:main thread : modulesProcessCnf params:
0289.268333574:main thread : load: 'imklog'
0289.268341934:main thread : Requested to load module 'imklog'
0289.268346200:main thread : loading module
'/usr/local/lib/rsyslog/imklog.so'
0289.268437349:main thread : module imklog of type 0 being loaded
(keepType=0).
0289.268445825:main thread : entry point 'isCompatibleWithFeature' not
present in module
0289.268450349:main thread : module config name is 'imklog'
0289.268453906:main thread : module imklog supports rsyslog v6 config
interface
0289.268459539:main thread : entry point 'newInpInst' not present in module
0289.268464395:main thread : module (global) param blk for imklog:
0289.268467614:main thread : logpath: (unset)
0289.268475219:main thread : permitnonkernelfacility: (unset)
0289.268482632:main thread : consoleloglevel: (unset)
0289.268489992:main thread : parsekerneltimestamp: (unset)
0289.268497365:main thread : keepkerneltimestamp: (unset)
0289.268504731:main thread : internalmsgfacility: (unset)
yydebug: state 0, reducing by rule 1 (conf :)
yydebug: after reduction, shifting from state 0 to state 1
yydebug: state 1, reading 259 (BEGINOBJ)
yydebug: state 1, shifting to state 2
yydebug: state 2, reducing by rule 16 (nvlst :)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 260 (ENDOBJ)
yydebug: state 22, shifting to state 45
yydebug: state 45, reducing by rule 7 (obj : BEGINOBJ nvlst ENDOBJ)
yydebug: after reduction, shifting from state 1 to state 18
yydebug: state 18, reducing by rule 2 (conf : conf obj)
yydebug: after reduction, shifting from state 0 to state 1
yydebug: state 1, reading 259 (BEGINOBJ)
yydebug: state 1, shifting to state 2
yydebug: state 2, reducing by rule 16 (nvlst :)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 260 (ENDOBJ)
yydebug: state 22, shifting to state 45
yydebug: state 45, reducing by rule 7 (obj : BEGINOBJ nvlst ENDOBJ)
yydebug: after reduction, shifting from state 1 to state 18
yydebug: state 18, reducing by rule 2 (conf : conf obj)
yydebug: after reduction, shifting from state 0 to state 1
yydebug: state 1, reading 259 (BEGINOBJ)
yydebug: state 1, shifting to state 2
yydebug: state 2, reducing by rule 16 (nvlst :)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 260 (ENDOBJ)
yydebug: state 22, shifting to state 45
yydebug: state 45, reducing by rule 7 (obj : BEGINOBJ nvlst ENDOBJ)
yydebug: after reduction, shifting from state 1 to state 18
yydebug: state 18, reducing by rule 2 (conf : conf obj)
yydebug: after reduction, shifting from state 0 to state 1
yydebug: state 1, reading 259 (BEGINOBJ)
yydebug: state 1, shifting to state 2
yydebug: state 2, reducing by rule 16 (nvlst :)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: sta0289.268545437:main thread : cnf:global:obj: obj: 'module'
0289.268552013:main thread : nvlst 0x12b1fd0:
0289.268555417:main thread : name: 'load', value 'omrelp'
0289.268559315:main thread : nvlstGetParam: name 'load', type 13,
valnode->bUsed 0
0289.268562754:main thread : modulesProcessCnf params:
0289.268571714:main thread : load: 'omrelp'
0289.268588118:main thread : Requested to load module 'omrelp'
0289.268597496:main thread : loading module
'/usr/local/lib/rsyslog/omrelp.so'
0289.269544253:main thread : module omrelp of type 1 being loaded
(keepType=0).
0289.269561739:main thread : entry point 'setModCnf' not present in module
0289.269569788:main thread : module config name is 'omrelp'
0289.269577149:main thread : entry point 'beginCnfLoad' not present in module
0289.269586078:main thread : entry point 'doHUP' not present in module
0289.269594129:main thread : entry point 'commitTransaction' not present in
module
0289.269612789:main thread : cnf:global:cfsysline:
$ActionForwardDefaultTemplate RSYSLOG_ForwardFormat # for plain TCP and UDP
0289.269626844:main thread : doGetWord: get newval 'RSYSLOG_ForwardFormat'
(len 21), hdlr 0x44de20
te 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 260 (ENDOBJ)
yydebug: state 22, shifting to state 45
yydebug: state 45, reducing by rule 7 (obj : BEGINOBJ nvlst ENDOBJ)
yydebug: after reduction, shifting from state 1 to state 18
yydebug: state 18, reducing by rule 2 (conf : conf obj)
yydebug: after reduction, shifting from state 0 to state 1
yydebug: state 1, reading 259 (BEGINOBJ)
yydebug: state 1, shifting to state 2
yydebug: state 2, reducing by rule 16 (nvlst :)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing 0289.269715631:main thread : cnf:global:obj:
obj: 'input'
0289.269728737:main thread : nvlst 0x12bb0b0:
0289.269735974:main thread : name: 'PersistStateInterval', value '5'
0289.269742703:main thread : name: 'Facility', value 'user'
0289.269749072:main thread : name: 'Severity', value 'notice'
0289.269755934:main thread : name: 'StateFile', value 'audit.state'
0289.269762446:main thread : name: 'Tag', value 'modsec'
0289.269769025:main thread : name: 'File', value
'/var/log/modsec/audit.log'
0289.269775502:main thread : name: 'type', value 'imfile'
0289.269783771:main thread : nvlstGetParam: name 'type', type 14,
valnode->bUsed 0
0289.269794400:main thread : input param blk after inputProcessCnf:
0289.269801444:main thread : type: 'imfile'
0289.269819420:main thread : newInpInst (imfile)
0289.269826983:main thread : nvlstGetParam: name 'file', type 14,
valnode->bUsed 0
0289.269834197:main thread : nvlstGetParam: name 'statefile', type 14,
valnode->bUsed 0
0289.269841348:main thread : nvlstGetParam: name 'tag', type 14,
valnode->bUsed 0
0289.269848761:main thread : nvlstGetParam: name 'severity', type 12,
valnode->bUsed 0
0289.269855637:main thread : symbolic name: notice ==> 5
0289.269875088:main thread : nvlstGetParam: name 'facility', type 11,
valnode->bUsed 0
0289.269882051:main thread : symbolic name: user ==> 8
0289.269895205:main thread : nvlstGetParam: name 'persiststateinterval',
type 6, valnode->bUsed 0
0289.269905979:main thread : input param blk in imfile:
0289.269912647:main thread : file: '/var/log/modsec/audit.log'
0289.269929011:main thread : statefile: 'audit.state'
0289.269944358:main thread : tag: 'modsec'
0289.269960414:main thread : severity: 5
0289.269975743:main thread : facility: 8
0289.269991404:main thread : ruleset: (unset)
0289.270007133:main thread : readmode: (unset)
0289.270022525:main thread : escapelf: (unset)
0289.270038204:main thread : maxlinesatonce: (unset)
0289.270053773:main thread : maxsubmitatonce: (unset)
0289.270068807:main thread : persiststateinterval: 5
by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 257 (NAME)
yydebug: state 22, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 22 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 2 to state 22
yydebug: state 22, reading 260 (ENDOBJ)
yydebug: state 22, shifting to state 45
yydebug: state 45, reducing by rule 7 (obj : BEGINOBJ nvlst ENDOBJ)
yydebug: after reduction, shifting from state 1 to state 18
yydebug: state 18, reducing by rule 2 (conf : conf obj)
yydebug: after reduction, shifting from state 0 to state 1
yydebug: state 1, reading 261 (BEGIN_ACTION)
yydebug: state 1, shifting to state 3
yydebug: state 3, reducing by rule 16 (nvlst :)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (0289.270194439:main thread :
nvlstGetParam: name 'type', type 14, valnode->bUsed 0
0289.270201147:main thread : action param blk after actionNewInst:
0289.270204479:main thread : name: (unset)
0289.270212338:main thread : type: 'omfile'
0289.270220368:main thread : action.writeallmarkmessages: (unset)
0289.270227706:main thread : action.execonlyeverynthtime: (unset)
0289.270235079:main thread : action.execonlyeverynthtimetimeout: (unset)
0289.270242397:main thread : action.execonlyonceeveryinterval: (unset)
0289.270249808:main thread : action.execonlywhenpreviousissuspended: (unset)
0289.270257154:main thread : action.repeatedmsgcontainsoriginalmsg: (unset)
0289.270264470:main thread : action.resumeretrycount: (unset)
0289.270271806:main thread : action.reportsuspension: (unset)
0289.270279117:main thread : action.reportsuspensioncontinuation: (unset)
0289.270286405:main thread : action.resumeinterval: (unset)
0289.270296297:main thread : newActInst (omfile)
0289.270301959:main thread : nvlstGetParam: name 'file', type 14,
valnode->bUsed 0
0289.270311873:main thread : nvlstGetParam: name 'sig.provider', type 13,
valnode->bUsed 0
0289.270315926:main thread : action param blk in omfile:
0289.270319125:main thread : dynafilecachesize: (unset)
0289.270326713:main thread : ziplevel: (unset)
0289.270334134:main thread : flushinterval: (unset)
0289.270341542:main thread : asyncwriting: (unset)
0289.270348891:main thread : veryrobustzip: (unset)
0289.270356160:main thread : flushontxend: (unset)
0289.270363421:main thread : iobuffersize: (unset)
0289.270370710:main thread : dirowner: (unset)
0289.270377963:main thread : dirownernum: (unset)
0289.270385307:main thread : dirgroup: (unset)
0289.270392612:main thread : dirgroupnum: (unset)
0289.270399852:main thread : fileowner: (unset)
0289.270407176:main thread : fileownernum: (unset)
0289.270414531:main thread : filegroup: (unset)
0289.270421867:main thread : filegroupnum: (unset)
0289.270429116:main thread : dircreatemode: (unset)
0289.270436470:main thread : filecreatemode: (unset)
0289.270443819:main thread : failonchownfailure: (unset)
0289.270451095:main thread : createdirs: (unset)
0289.270458461:main thread : sync: (unset)
0289.270465726:main thread : file: '/var/log/syslog'
0289.270473393:main thread : dynafile: (unset)
0289.270480711:main thread : sig.provider: 'gt'
0289.270488234:main thread : cry.provider: (unset)
0289.270495492:main thread : closetimeout: (unset)
0289.270502735:main thread : template: (unset)
0289.270517455:main thread : caller requested object 'lmsig_gt', not found
(iRet -3003)
0289.270521685:main thread : Requested to load module 'lmsig_gt'
0289.270526119:main thread : loading module
'/usr/local/lib/rsyslog/lmsig_gt.so'
0289.278404414:main thread : module lmsig_gt of type 2 being loaded
(keepType=0).
0289.278422753:main thread : entry point 'isCompatibleWithFeature' not
present in module
0289.278426733:main thread : entry point 'setModCnf' not present in module
0289.278430248:main thread : entry point 'getModCnfName' not present in
module
0289.278433663:main thread : entry point 'beginCnfLoad' not present in module
0289.278439712:main thread : source file omfile.c requested reference for
module 'lmsig_gt', reference count now 1
0289.278447574:main thread : nvlstGetParam: name 'sig.keeprecordhashes',
type 4, valnode->bUsed 0
0289.278451866:main thread : nvlstGetParam: name 'sig.keeptreehashes', type
4, valnode->bUsed 0
0289.278455247:main thread : sig param blk in lmsig_gt:
0289.278458503:main thread : sig.hashfunction: (unset)
0289.278466380:main thread : sig.timestampservice: (unset)
0289.278473956:main thread : sig.block.sizelimit: (unset)
0289.278481386:main thread : sig.keeprecordhashes: 1
0289.278489060:main thread : sig.keeptreehashes: 1
0289.278497732:main thread : loaded signature provider lmsig_gt, data
instance at 0x12bb060
0289.278506724:main thread : Module builtin:omfile processes this action.
0289.278515872:main thread : template: 'RSYSLOG_FileFormat' assigned
0289.278528079:main thread : nvlstGetParam: name 'queue.type', type 16,
valnode->bUsed 0
0289.278534518:main thread : queue param blk:
0289.278537928:main thread : queue.filename: (unset)
0289.278545735:main thread : queue.spooldirectory: (unset)
0289.278563121:main thread : queue.size: (unset)
0289.278577076:main thread : queue.dequeuebatchsize: (unset)
0289.278587783:main thread : queue.maxdiskspace: (unset)
0289.278595620:main thread : queue.highwatermark: (unset)
0289.278603162:main thread : queue.lowwatermark: (unset)
0289.278610654:main thread : queue.fulldelaymark: (unset)
0289.278618193:main thread : queue.lightdelaymark: (unset)
0289.278625636:main thread : queue.discardmark: (unset)
0289.278632998:main thread : queue.discardseverity: (unset)
0289.278640371:main thread : queue.checkpointinterval: (unset)
0289.278647686:main thread : queue.syncqueuefiles: (unset)
0289.278661092:main thread : queue.type: 3
0289.278669002:main thread : queue.workerthreads: (unset)
0289.278676455:main thread : queue.timeoutshutdown: (unset)
0289.278683833:main thread : queue.timeoutactioncompletion: (unset)
0289.278691128:main thread : queue.timeoutenqueue: (unset)
0289.278698571:main thread : queue.timeoutworkerthreadshutdown: (unset)
0289.278705968:main thread : queue.workerthreadminimummessages: (unset)
0289.278713295:main thread : queue.maxfilesize: (unset)
0289.278720599:main thread : queue.saveonshutdown: (unset)
0289.278727931:main thread : queue.dequeueslowdown: (unset)
0289.278735322:main thread : queue.dequeuetimebegin: (unset)
0289.278742732:main thread : queue.dequeuetimeend: (unset)
0289.278750043:main thread : queue.cry.provider: (unset)
0289.278762700:main thread : action 1 queue: parameter dump:
0289.278766744:main thread : action 1 queue: queue.filename '[NONE]'
0289.278770195:main thread : action 1 queue: queue.size: 1000
0289.278773461:main thread : action 1 queue: queue.dequeuebatchsize: 128
0289.278776677:main thread : action 1 queue: queue.maxdiskspace: 0
0289.278779817:main thread : action 1 queue: queue.highwatermark: -1
0289.278782907:main thread : action 1 queue: queue.lowwatermark: -1
0289.278786054:main thread : action 1 queue: queue.fulldelaymark: -1
0289.278789254:main thread : action 1 queue: queue.lightdelaymark: -1
0289.278792396:main thread : action 1 queue: queue.discardmark: -1
0289.278795477:main thread : action 1 queue: queue.discardseverity: 8
0289.278798587:main thread : action 1 queue: queue.checkpointinterval: 0
0289.278801679:main thread : action 1 queue: queue.syncqueuefiles: 0
0289.278804968:main thread : action 1 queue: queue.type: 3 [Direct]
0289.278808117:main thread : action 1 queue: queue.workerthreads: 1
0289.278811175:main thread : action 1 queue: queue.timeoutshutdown: 0
0289.278814374:main thread : action 1 queue: queue.timeoutactioncompletion:
1000
0289.278817523:main thread : action 1 queue: queue.timeoutenqueue: 2000
0289.278820803:main thread : action 1 queue:
queue.timeoutworkerthreadshutdown: 60000
0289.278823992:main thread : action 1 queue:
queue.workerthreadminimummessages: -1
0289.278827205:main thread : action 1 queue: queue.maxfilesize: 1048576
0289.278830375:main thread : action 1 queue: queue.saveonshutdown: 1
0289.278833516:main thread : action 1 queue: queue.dequeueslowdown: 0
0289.278836600:main thread : action 1 queue: queue.dequeuetimebegin: 0
0289.278839729:main thread : action 1 queue: queuedequeuetimend.: 25
0289.278843055:main thread : Action 0x12bb4d0: queue 0x12e2560 created
0289.278855605:main thread : cnf:global:script
nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 260 (ENDOBJ)
yydebug: state 23, shifting to state 47
yydebug: state 47, reducing by rule 34 (s_act : BEGIN_ACTION nvlst ENDOBJ)
yydebug: after reduction, shifting from state 1 to state 20
yydebug: state 20, reducing by rule 32 (actlst : s_act)
yydebug: after reduction, shifting from state 1 to state 21
yydebug: state 21, reading 261 (BEGIN_ACTION)
yydebug: state 21, reducing by rule 23 (stmt : actlst)
yydebug: after reduction, shifting from state 1 to state 19
yydebug: state 19, reducing by rule 3 (conf : conf stmt)
yydebug: after reduction, shifting from state 0 to state 1
yydebug: state 1, shifting to state 3
yydebug: state 3, reducing by rule 16 (nvlst :)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shifting to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 257 (NAME)
yydebug: state 23, shifting to state 44
yydebug: state 44, reading 61 ('=')
yydebug: state 44, shifting to state 80
yydebug: state 80, reading 284 (STRING)
yydebug: state 80, shiftin0289.278931627:main thread : nvlstGetParam: name
'type', type 14, valnode->bUsed 0
0289.278937212:main thread : nvlstGetParam: name 'action.resumeretrycount',
type 6, valnode->bUsed 0
0289.278941556:main thread : nvlstGetParam: name 'action.resumeinterval',
type 6, valnode->bUsed 0
0289.278944839:main thread : action param blk after actionNewInst:
0289.278947963:main thread : name: (unset)
0289.278955646:main thread : type: 'omrelp'
0289.278963873:main thread : action.writeallmarkmessages: (unset)
0289.278973449:main thread : action.execonlyeverynthtime: (unset)
0289.278988534:main thread : action.execonlyeverynthtimetimeout: (unset)
0289.279002457:main thread : action.execonlyonceeveryinterval: (unset)
0289.279019027:main thread : action.execonlywhenpreviousissuspended: (unset)
0289.279033658:main thread : action.repeatedmsgcontainsoriginalmsg: (unset)
0289.279042473:main thread : action.resumeretrycount: 10
0289.279050393:main thread : action.reportsuspension: (unset)
0289.279057994:main thread : action.reportsuspensioncontinuation: (unset)
0289.279065502:main thread : action.resumeinterval: 5
0289.279077461:main thread : nvlstGetParam: name 'target', type 13,
valnode->bUsed 0
0289.279086024:main thread : nvlstGetParam: name 'port', type 13,
valnode->bUsed 0
0289.279100088:main thread : Module omrelp processes this action.
0289.279124934:main thread : template: 'RSYSLOG_ForwardFormat' assigned
0289.279139129:main thread : nvlstGetParam: name 'queue.filename', type 13,
valnode->bUsed 0
0289.279143812:main thread : nvlstGetParam: name 'queue.spooldirectory',
type 13, valnode->bUsed 0
0289.279147756:main thread : nvlstGetParam: name 'queue.size', type 9,
valnode->bUsed 0
0289.279151870:main thread : nvlstGetParam: name 'queue.maxdiskspace', type
9, valnode->bUsed 0
0289.279155403:main thread : nvlstGetParam: name 'queue.highwatermark', type
6, valnode->bUsed 0
0289.279160537:main thread : nvlstGetParam: name 'queue.type', type 16,
valnode->bUsed 0
0289.279165748:main thread : nvlstGetParam: name 'queue.saveonshutdown',
type 4, valnode->bUsed 0
0289.279169688:main thread : queue param blk:
0289.279172901:main thread : queue.filename: 'forwarding'
0289.279180840:main thread : queue.spooldirectory: '/var/lib/rsyslog'
0289.279188624:main thread : queue.size: 16384
0289.279196310:main thread : queue.dequeuebatchsize: (unset)
0289.279203754:main thread : queue.maxdiskspace: 1073741824
0289.279211336:main thread : queue.highwatermark: 12000
0289.279218919:main thread : queue.lowwatermark: (unset)
0289.279226206:main thread : queue.fulldelaymark: (unset)
0289.279233491:main thread : queue.lightdelaymark: (unset)
0289.279240778:main thread : queue.discardmark: (unset)
0289.279248071:main thread : queue.discardseverity: (unset)
0289.279255415:main thread : queue.checkpointinterval: (unset)
0289.279262757:main thread : queue.syncqueuefiles: (unset)
0289.279270093:main thread : queue.type: 1
0289.279277533:main thread : queue.workerthreads: (unset)
0289.279284742:main thread : queue.timeoutshutdown: (unset)
0289.279292034:main thread : queue.timeoutactioncompletion: (unset)
0289.279299328:main thread : queue.timeoutenqueue: (unset)
0289.279306809:main thread : queue.timeoutworkerthreadshutdown: (unset)
0289.279314333:main thread : queue.workerthreadminimummessages: (unset)
0289.279321643:main thread : queue.maxfilesize: (unset)
0289.279328926:main thread : queue.saveonshutdown: 1
0289.279336350:main thread : queue.dequeueslowdown: (unset)
0289.279343573:main thread : queue.dequeuetimebegin: (unset)
0289.279350794:main thread : queue.dequeuetimeend: (unset)
0289.279358110:main thread : queue.cry.provider: (unset)
0289.279368325:main thread : action 2 queue: parameter dump:
0289.279371693:main thread : action 2 queue: queue.filename 'forwarding'
0289.279374883:main thread : action 2 queue: queue.size: 16384
0289.279378018:main thread : action 2 queue: queue.dequeuebatchsize: 128
0289.279381188:main thread : action 2 queue: queue.maxdiskspace: 1073741824
0289.279384344:main thread : action 2 queue: queue.highwatermark: 12000
0289.279387397:main thread : action 2 queue: queue.lowwatermark: -1
0289.279390459:main thread : action 2 queue: queue.fulldelaymark: -1
0289.279393547:main thread : action 2 queue: queue.lightdelaymark: -1
0289.279396637:main thread : action 2 queue: queue.discardmark: -1
0289.279399696:main thread : action 2 queue: queue.discardseverity: 8
0289.279402797:main thread : action 2 queue: queue.checkpointinterval: 0
0289.279405874:main thread : action 2 queue: queue.syncqueuefiles: 0
0289.279409093:main thread : action 2 queue: queue.type: 1 [LinkedList]
0289.279412210:main thread : action 2 queue: queue.workerthreads: 1
0289.279415287:main thread : action 2 queue: queue.timeoutshutdown: 0
0289.279418422:main thread : action 2 queue: queue.timeoutactioncompletion:
1000
0289.279421597:main thread : action 2 queue: queue.timeoutenqueue: 2000
0289.279424707:main thread : action 2 queue:
queue.timeoutworkerthreadshutdown: 60000
0289.279427818:main thread : action 2 queue:
queue.workerthreadminimummessages: -1
0289.279430993:main thread : action 2 queue: queue.maxfilesize: 1048576
0289.279440206:main thread : action 2 queue: queue.saveonshutdown: 1
0289.279443612:main thread : action 2 queue: queue.dequeueslowdown: 0
0289.279446828:main thread : action 2 queue: queue.dequeuetimebegin: 0
0289.279449962:main thread : action 2 queue: queuedequeuetimend.: 25
0289.279453282:main thread : Action 0x12e29d0: queue 0x12e2f10 created
0289.279461462:main thread : config parser: reached end of file
/etc/rsyslog.conf
0289.279465277:main thread : config parser: parsing completed
0289.279471167:main thread : cnf:global:script
0289.279476003:main thread : Number of actions in this configuration: 2
0289.279479449:main thread : begin ruleset optimization phase
0289.279483170:main thread : ruleset 'RSYSLOG_DefaultRuleset' before
optimization:
0289.279489304:main thread : ruleset 0x12a6570: rsyslog ruleset
RSYSLOG_DefaultRuleset:
0289.279493724:main thread : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0289.279497064:main thread : ACTION 1 [omrelp:action(type="omrelp" ...)]
0289.279500166:main thread : ruleset 0x12a6570: ruleset
RSYSLOG_DefaultRuleset assigned parser list:
0289.279503671:main thread : ruleset 'RSYSLOG_DefaultRuleset' after
optimization:
0289.279506735:main thread : ruleset 0x12a6570: rsyslog ruleset
RSYSLOG_DefaultRuleset:
0289.279510129:main thread : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0289.279513231:main thread : ACTION 1 [omrelp:action(type="omrelp" ...)]
0289.279516210:main thread : ruleset 0x12a6570: ruleset
RSYSLOG_DefaultRuleset assigned parser list:
0289.279519366:main thread : ruleset optimization phase finished.
0289.279522486:main thread : telling rsyslog core that config load for
0x12a3490 is done
0289.279528615:main thread : Timezone information table (0 entries):
0289.279532363:main thread : telling modules that config load for 0x12a3490
is done
0289.279538434:main thread : imfile: opmode is 1, polling interval is 10
0289.279542636:main thread : telling modules to check config 0x12a3490
0289.279545973:main thread : module builtin:omfile tells us config can be
activated
0289.279549182:main thread : module imfile tells us config can be activated
0289.279552403:main thread : module imuxsock tells us config can be activated
0289.279555513:main thread : module imklog tells us config can be activated
0289.279558646:main thread : rsyslog finished loading master config 0x12a3490
0289.279561713:main thread : configuration object 0x12a3490
0289.279564492:main thread : Global Settings:
0289.279567514:main thread : bDebugPrintTemplateList.............: 1
0289.279570431:main thread : bDebugPrintModuleList : 0
0289.279573302:main thread : bDebugPrintCfSysLineHandlerList.....: 0
0289.279576431:main thread : bLogStatusMsgs : 1
0289.279579268:main thread : bErrMsgToStderr.....................: 1
0289.279582246:main thread : drop Msgs with malicious PTR Record : 0
0289.279585167:main thread : All Rulesets:
0289.279588228:main thread : ruleset 0x12a6570: rsyslog ruleset
RSYSLOG_DefaultRuleset:
0289.279591590:main thread : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0289.279594702:main thread : ACTION 1 [omrelp:action(type="omrelp" ...)]
0289.279597656:main thread : ruleset 0x12a6570: ruleset
RSYSLOG_DefaultRuleset assigned parser list:
0289.279600698:main thread : End of Rulesets.
0289.279603477:main thread :
0289.279607541:main thread : Template: Name='RSYSLOG_DebugFormat'
0289.279613324:main thread : Entry(12a9050): type 1, (CONSTANT),
value: 'Debug line with all properties:
FROMHOST: ''
0289.279621083:main thread : Entry(12a9110): type 2, (FIELD), value:
'7'
0289.279628828:main thread : Entry(12a9280): type 1, (CONSTANT),
value: '', fromhost-ip: ''
0289.279636273:main thread : Entry(12a9340): type 2, (FIELD), value:
'8'
0289.279643701:main thread : Entry(12a94b0): type 1, (CONSTANT),
value: '', HOSTNAME: ''
0289.279651142:main thread : Entry(12a9570): type 2, (FIELD), value:
'3'
0289.279662348:main thread : Entry(12a96e0): type 1, (CONSTANT),
value: '', PRI: '
0289.279669886:main thread : Entry(12a97a0): type 2, (FIELD), value:
'9'
0289.279677449:main thread : Entry(12a9910): type 1, (CONSTANT),
value: ',
syslogtag ''
0289.279685112:main thread : Entry(12a99d0): type 2, (FIELD), value:
'4'
0289.279692782:main thread : Entry(12a9b40): type 1, (CONSTANT),
value: '', programname: ''
0289.279700169:main thread : Entry(12a9c00): type 2, (FIELD), value:
'17'
0289.279707542:main thread : Entry(12a9d70): type 1, (CONSTANT),
value: '', APP-NAME: ''
0289.279714939:main thread : Entry(12a9e30): type 2, (FIELD), value:
'20'
0289.279722307:main thread : Entry(12a9fa0): type 1, (CONSTANT),
value: '', PROCID: ''
0289.279729646:main thread : Entry(12aa060): type 2, (FIELD), value:
'21'
0289.279736989:main thread : Entry(12aa1d0): type 1, (CONSTANT),
value: '', MSGID: ''
0289.279744298:main thread : Entry(12aa290): type 2, (FIELD), value:
'22'
0289.279751619:main thread : Entry(12aa400): type 1, (CONSTANT),
value: '',
TIMESTAMP: ''
0289.279758969:main thread : Entry(12aa4c0): type 2, (FIELD), value:
'2'
0289.279766195:main thread : Entry(12aa630): type 1, (CONSTANT),
value: '', STRUCTURED-DATA: ''
0289.279773618:main thread : Entry(12aa6f0): type 2, (FIELD), value:
'19'
0289.279780892:main thread : Entry(12aa860): type 1, (CONSTANT),
value: '',
msg: ''
0289.279788247:main thread : Entry(12aa920): type 2, (FIELD), value:
'1'
0289.279795576:main thread : Entry(12aaa90): type 1, (CONSTANT),
value: ''
escaped msg: ''
0289.279803000:main thread : Entry(12aab50): type 2, (FIELD), value:
'1' [drop control-characters] [COMPLEX]
0289.279816232:main thread : Entry(12aacc0): type 1, (CONSTANT),
value: ''
inputname: '
0289.279823515:main thread : Entry(12aad80): type 2, (FIELD), value:
'6'
0289.279830766:main thread : Entry(12aaef0): type 1, (CONSTANT),
value: ' rawmsg: ''
0289.279837988:main thread : Entry(12aafb0): type 2, (FIELD), value:
'5'
0289.279845302:main thread : Entry(12ab120): type 1, (CONSTANT),
value: ''
$!:'
0289.279852549:main thread : Entry(12ab1e0): type 2, (FIELD), value:
'200' [EE-Property: '!']
0289.279862299:main thread : Entry(12ab370): type 1, (CONSTANT),
value: '
$.:'
0289.279869582:main thread : Entry(12ab430): type 2, (FIELD), value:
'202' [Local Var: '!']
0289.279879259:main thread : Entry(12ab5c0): type 1, (CONSTANT),
value: '
$/:'
0289.279886524:main thread : Entry(12ab680): type 2, (FIELD), value:
'203'
0289.279893949:main thread : Entry(12ab810): type 1, (CONSTANT),
value: '
'
0289.279901250:main thread : Template: Name='RSYSLOG_SyslogProtocol23Format'
0289.279906423:main thread : Entry(12aba00): type 1, (CONSTANT),
value: '<'
0289.279913727:main thread : Entry(12abac0): type 2, (FIELD), value:
'9'
0289.279921034:main thread : Entry(12abc30): type 1, (CONSTANT),
value: '>1 '
0289.279928382:main thread : Entry(12abcf0): type 2, (FIELD), value:
'2' [Format as RFC3339-Date] [COMPLEX]
0289.279940232:main thread : Entry(12abe60): type 1, (CONSTANT),
value: ' '
0289.279947474:main thread : Entry(12abf20): type 2, (FIELD), value:
'3'
0289.279954789:main thread : Entry(12ac090): type 1, (CONSTANT),
value: ' '
0289.279962197:main thread : Entry(12ac150): type 2, (FIELD), value:
'20'
0289.279969505:main thread : Entry(12ac2c0): type 1, (CONSTANT),
value: ' '
0289.279976843:main thread : Entry(12ac380): type 2, (FIELD), value:
'21'
0289.279984169:main thread : Entry(12ac4f0): type 1, (CONSTANT),
value: ' '
0289.279991450:main thread : Entry(12ac5b0): type 2, (FIELD), value:
'22'
0289.279998789:main thread : Entry(12ac720): type 1, (CONSTANT),
value: ' '
0289.280006031:main thread : Entry(12ac7e0): type 2, (FIELD), value:
'19'
0289.280013380:main thread : Entry(12ac950): type 1, (CONSTANT),
value: ' '
0289.280020646:main thread : Entry(12aca10): type 2, (FIELD), value:
'1'
0289.280033140:main thread : Entry(12acb80): type 1, (CONSTANT),
value: '
'
0289.280046309:main thread : Template: Name='RSYSLOG_FileFormat'
0289.280054880:main thread : Template: Name='RSYSLOG_TraditionalFileFormat'
0289.280060345:main thread : Template: Name=' WallFmt'
0289.280065680:main thread : Entry(12ace90): type 1, (CONSTANT),
value: '
Message from syslogd@'
0289.280073345:main thread : Entry(12acf50): type 2, (FIELD), value:
'3'
0289.280081112:main thread : Entry(12ad0c0): type 1, (CONSTANT),
value: ' at '
0289.280088807:main thread : Entry(12ad180): type 2, (FIELD), value:
'16'
0289.280096392:main thread : Entry(12ad2f0): type 1, (CONSTANT),
value: ' ...
'
0289.280103817:main thread : Entry(12ad3b0): type 2, (FIELD), value:
'4'
0289.280129477:main thread : Entry(12ad520): type 2, (FIELD), value:
'1'
0289.280137584:main thread : Entry(12ad600): type 1, (CONSTANT),
value: '
'
0289.280145228:main thread : Template: Name='RSYSLOG_ForwardFormat'
0289.280153095:main thread : Template:
Name='RSYSLOG_TraditionalForwardFormat'
0289.280163452:main thread : Template: Name=' StdUsrMsgFmt'
0289.280174342:main thread : Entry(12ad910): type 1, (CONSTANT),
value: ' '
0289.280188376:main thread : Entry(12ad9d0): type 2, (FIELD), value:
'4'
0289.280204646:main thread : Entry(12adb40): type 2, (FIELD), value:
'1'
0289.280213710:main thread : Entry(12adc20): type 1, (CONSTANT),
value: '
'
0289.280221218:main thread : Template: Name=' StdDBFmt' [SQL-Format (MySQL)]
0289.280228894:main thread : Entry(12adf00): type 1, (CONSTANT),
value: 'insert into SystemEvents (Message, Facility, FromHost, Priority,
DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values (''
0289.280236656:main thread : Entry(12adfc0): type 2, (FIELD), value:
'1'
0289.280244421:main thread : Entry(12ae130): type 1, (CONSTANT),
value: '', '
0289.280252056:main thread : Entry(12ae1f0): type 2, (FIELD), value:
'12'
0289.280259888:main thread : Entry(12ae360): type 1, (CONSTANT),
value: ', ''
0289.280267325:main thread : Entry(12ae420): type 2, (FIELD), value:
'3'
0289.280274981:main thread : Entry(12ae590): type 1, (CONSTANT),
value: '', '
0289.280282390:main thread : Entry(12ae650): type 2, (FIELD), value:
'14'
0289.280289867:main thread : Entry(12ae7c0): type 1, (CONSTANT),
value: ', ''
0289.280297282:main thread : Entry(12ae880): type 2, (FIELD), value:
'2' [Format as MySQL-Date] [COMPLEX]
0289.280309329:main thread : Entry(12ae9f0): type 1, (CONSTANT),
value: '', ''
0289.280316895:main thread : Entry(12aeab0): type 2, (FIELD), value:
'16' [Format as MySQL-Date] [COMPLEX]
0289.280328785:main thread : Entry(12aec20): type 1, (CONSTANT),
value: '', '
0289.280336142:main thread : Entry(12aece0): type 2, (FIELD), value:
'11'
0289.280343643:main thread : Entry(12aee50): type 1, (CONSTANT),
value: ', ''
0289.280351027:main thread : Entry(12aef10): type 2, (FIELD), value:
'4'
0289.280358602:main thread : Entry(12af080): type 1, (CONSTANT),
value: '')'
0289.280365963:main thread : Template: Name='RSYSLOG_SysklogdFileFormat'
0289.280371147:main thread : Entry(12af1e0): type 2, (FIELD), value:
'2'
0289.280378619:main thread : Entry(12af350): type 1, (CONSTANT),
value: ' '
0289.280386000:main thread : Entry(12af410): type 2, (FIELD), value:
'3'
0289.280393510:main thread : Entry(12af580): type 1, (CONSTANT),
value: ' '
0289.280400885:main thread : Entry(12af640): type 2, (FIELD), value:
'4'
0289.280408277:main thread : Entry(12af7b0): type 2, (FIELD), value:
'1' [SP iff no first SP] [COMPLEX]
0289.280438591:main thread : Entry(12af890): type 2, (FIELD), value:
'1'
0289.280446836:main thread : Entry(12af970): type 1, (CONSTANT),
value: '
'
0289.280454412:main thread : Template: Name=' StdPgSQLFmt' [SQL-Format
(standard SQL)]
0289.280462135:main thread : Entry(12afc50): type 1, (CONSTANT),
value: 'insert into SystemEvents (Message, Facility, FromHost, Priority,
DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag) values (''
0289.280474588:main thread : Entry(12afd10): type 2, (FIELD), value:
'1'
0289.280482440:main thread : Entry(12afe80): type 1, (CONSTANT),
value: '', '
0289.280490003:main thread : Entry(12aff40): type 2, (FIELD), value:
'12'
0289.280497785:main thread : Entry(12b00b0): type 1, (CONSTANT),
value: ', ''
0289.280505501:main thread : Entry(12b0170): type 2, (FIELD), value:
'3'
0289.280512996:main thread : Entry(12b02e0): type 1, (CONSTANT),
value: '', '
0289.280520360:main thread : Entry(12b03a0): type 2, (FIELD), value:
'14'
0289.280527858:main thread : Entry(12b0510): type 1, (CONSTANT),
value: ', ''
0289.280535246:main thread : Entry(12b05d0): type 2, (FIELD), value:
'2' [Format as PgSQL-Date] [COMPLEX]
0289.280547261:main thread : Entry(12b0740): type 1, (CONSTANT),
value: '', ''
0289.280554699:main thread : Entry(12b0800): type 2, (FIELD), value:
'16' [Format as PgSQL-Date] [COMPLEX]
0289.280566625:main thread : Entry(12b0970): type 1, (CONSTANT),
value: '', '
0289.280574034:main thread : Entry(12b0a30): type 2, (FIELD), value:
'11'
0289.280581535:main thread : Entry(12b0ba0): type 1, (CONSTANT),
value: ', ''
0289.280588948:main thread : Entry(12b0c60): type 2, (FIELD), value:
'4'
0289.280596514:main thread : Entry(12b0dd0): type 1, (CONSTANT),
value: '')'
0289.280603806:main thread : Template: Name=' StdJSONFmt'
0289.280609046:main thread : Entry(12b0fb0): type 1, (CONSTANT),
value: '{"message":"'
0289.280616685:main thread : Entry(12b1070): type 2, (FIELD), value:
'1' [format as JSON] [COMPLEX]
0289.280628576:main thread : Entry(12b11e0): type 1, (CONSTANT),
value: '","fromhost":"'
0289.280636015:main thread : Entry(12b12a0): type 2, (FIELD), value:
'3' [format as JSON] [COMPLEX]
0289.280647865:main thread : Entry(12b1410): type 1, (CONSTANT),
value: '","facility":"'
0289.280655240:main thread : Entry(12b14d0): type 2, (FIELD), value:
'13'
0289.280662685:main thread : Entry(12b1640): type 1, (CONSTANT),
value: '","priority":"'
0289.280670062:main thread : Entry(12b1700): type 2, (FIELD), value:
'15'
0289.280677474:main thread : Entry(12b1870): type 1, (CONSTANT),
value: '","timereported":"'
0289.280684882:main thread : Entry(12b1930): type 2, (FIELD), value:
'2' [Format as RFC3339-Date] [COMPLEX]
0289.280696864:main thread : Entry(12b1aa0): type 1, (CONSTANT),
value: '","timegenerated":"'
0289.280704344:main thread : Entry(12b1b60): type 2, (FIELD), value:
'16' [Format as RFC3339-Date] [COMPLEX]
0289.280716262:main thread : Entry(12b1cd0): type 1, (CONSTANT),
value: '"}'
0289.280723599:main thread : Template:
Name='RSYSLOG_omudpspoofDfltSourceTpl'
0289.280728818:main thread : Entry(12b1e30): type 2, (FIELD), value:
'8'
0289.280736451:main thread : Main queue size 100000 messages.
0289.280739776:main thread : Main queue worker threads: 2, wThread shutdown:
60000, Perists every 0 updates.
0289.280743033:main thread : Main queue timeouts: shutdown: 1500, action
completion shutdown: 1000, enq: 2000
0289.280746339:main thread : Main queue watermarks: high: 80000, low: 20000,
discard: 98000, discard-severity: 8
0289.280749504:main thread : Main queue save on shutdown 1, max disk space
allowed 0
0289.280752545:main thread : Work Directory: '/var/lib/rsyslog'.
0289.280755659:main thread : Modules used in this configuration:
0289.280758751:main thread : builtin:omfile
0289.280761822:main thread : builtin:ompipe
0289.280764713:main thread : builtin-shell
0289.280767645:main thread : builtin:omdiscard
0289.280770585:main thread : builtin:omfwd
0289.280773489:main thread : builtin:omusrmsg
0289.280776379:main thread : builtin:pmrfc5424
0289.280779252:main thread : builtin:pmrfc3164
0289.280782091:main thread : builtin:smfile
0289.280784999:main thread : builtin:smtradfile
0289.280787879:main thread : builtin:smfwd
0289.280794122:main thread : builtin:smtradfwd
0289.280797393:main thread : imfile
0289.280800368:main thread : imuxsock
0289.280803338:main thread : imklog
0289.280806339:main thread : omrelp
0289.280814732:main thread : GenerateLocalHostName uses 'server'
0289.280820068:main thread : ratelimit:rsyslogd[dflt]:new
ratelimiter:bReduceRepeatMsgs 0
0289.280824024:main thread : ratelimit:rsyslogd[internal_messages]:new
ratelimiter:bReduceRepeatMsgs 0
0289.280834799:main thread : Writing pidfile '/var/run/rsyslogd.pid'.
0289.280959793:main thread : telling modules to activate config (before
dropping privs) 0x12a3490
0289.280966184:main thread : pre priv drop activating config 0x12a3490 for
module imuxsock
0289.280970898:main thread : imuxsock: allocating memory for 0 listeners
0289.280980654:main thread : ratelimit:imuxsock:new
ratelimiter:bReduceRepeatMsgs 0
0289.281405338:main thread : imuxsock: Opened UNIX socket '/dev/log' (fd 3).
0289.281414425:main thread : pre priv drop activating config 0x12a3490 for
module imklog
0289.281437794:main thread : telling modules to activate config 0x12a3490
0289.281442206:main thread : activating config 0x12a3490 for module
builtin:omfile
0289.281446120:main thread : activating config 0x12a3490 for module imfile
0289.281451859:main thread : ratelimit:imfile[/var/log/modsec/audit.log]:new
ratelimiter:bReduceRepeatMsgs 0
0289.281459338:main thread : activating config 0x12a3490 for module imuxsock
0289.281463061:main thread : activating config 0x12a3490 for module imklog
0289.281468200:main thread : iterateAllActions calling into action 0x12bb4d0
0289.281471827:main thread : action 1 queue: starting queue
0289.281482284:main thread : action 1 queue: params: type 3, enq-only 0,
disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 1000,
lqsize 0, pqsize 0, child 0, full delay 970, light delay 700, deq batch size
128, high wtrmrk 900, low wtrmrk 700, discardmrk 980, max wrkr 1, min msgs f.
wrkr 1000
0289.281486704:main thread : Action builtin:omfile[0x12bb4d0]: queue
0x12e2560 started
0289.281489942:main thread : iterateAllActions calling into action 0x12e29d0
0289.281492865:main thread : action 2 queue: starting queue
0289.281496733:main thread : action 2 queue: is disk-assisted, disk will be
used on demand
0289.281501661:main thread : action 2 queue: params: type 1, enq-only 0,
disk assisted 1, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize
16384, lqsize 0, pqsize 0, child 0, full delay 6000, light delay 11410, deq
batch size 128, high wtrmrk 12000, low wtrmrk 11410, discardmrk 15974, max wrkr
1, min msgs f. wrkr 16384
0289.281511855:main thread : action 2 queue:Reg: finalizing construction of
worker thread pool (numworkerThreads 1)
0289.281517533:main thread : action 2 queue:Reg/w0: finalizing construction
of worker instance data (for 2 actions)
0289.281523268:main thread : action 2 queue:DAwpool: finalizing construction
of worker thread pool (numworkerThreads 1)
0289.281527570:main thread : action 2 queue:DAwpool/w0: finalizing
construction of worker instance data (for 2 actions)
0289.281534578:main thread : action 2 queue[DA]: starting queue
0289.281539816:main thread : action 2 queue[DA]: .qi file name is
'/var/lib/rsyslog/forwarding.qi', len 30
0289.281543298:main thread : action 2 queue[DA]: I am a child
0289.281551693:main thread : action 2 queue[DA]: clean startup, no .qi file
found
0289.281555475:main thread : action 2 queue[DA]: state -2040 reading .qi
file - can not read persisted info (if any)
0289.281564193:main thread : file stream N/A params: flush interval 0, async
write 0
0289.281571793:main thread : file stream N/A params: flush interval 0, async
write 0
0289.281578486:main thread : file stream N/A params: flush interval 0, async
write 0
0289.281585975:main thread : action 2 queue[DA]: params: type 2, enq-only 0,
disk assisted 0, spoolDir '/var/lib/rsyslog', maxFileSz 1048576, maxQSize 0,
lqsize 0, pqsize 0, child 1, full delay -1, light delay -1, deq batch size 8,
high wtrmrk 0, low wtrmrk 1, discardmrk 0, max wrkr 1, min msgs f. wrkr 0
0289.281596516:main thread : action 2 queue[DA]:Reg: finalizing construction
of worker thread pool (numworkerThreads 1)
0289.281601010:main thread : action 2 queue[DA]:Reg/w0: finalizing
construction of worker instance data (for 2 actions)
0289.281606945:main thread : action 2 queue[DA]: queue finished
initialization
0289.281613591:main thread : action 2 queue: DA queue initialized, disk
queue 0x12b2e80
0289.281617108:main thread : action 2 queue: queue finished initialization
0289.281621958:main thread : Action omrelp[0x12e29d0]: queue 0x12e2f10
started
0289.281626190:main thread : Activating Ruleset Queue[(nil)] for Ruleset
RSYSLOG_DefaultRuleset
0289.281630006:main thread : activateMainQueue: mainq cnf obj ptr is (nil)
0289.281636310:main thread : main Q: starting queue
0289.281647487:main thread : main Q: is NOT disk-assisted
0289.281653012:main thread : main Q: params: type 0, enq-only 0, disk
assisted 0, spoolDir '/var/lib/rsyslog', 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
0289.281657750:main thread : main Q:Reg: finalizing construction of worker
thread pool (numworkerThreads 2)
0289.281661858:main thread : main Q:Reg/w0: finalizing construction of
worker instance data (for 2 actions)
0289.281672012:main thread : main Q:Reg/w1: finalizing construction of
worker instance data (for 2 actions)
0289.281678227:main thread : main Q: queue finished initialization
0289.281683504:main thread : Main processing queue is initialized and running
0289.281687889:main thread : running module imfile with config 0x12b5670,
term mode: cooperative/SIGTTIN
0289.281757165:main thread : running module imuxsock with config 0x12b74a0,
term mode: cooperative/SIGTTIN
0289.281788532:main thread : running module imklog with config 0x12b8610,
term mode: cancel
0289.281798799:7faea06f5700: thread created, tid 32495, name 'in:imfile'
0289.281823262:main thread : configuration 0x12a3490 activated
0289.281829690:7faea06f5700: set thread name to 'in:imfile'
0289.281849015:7fae9fcf4700: thread created, tid 32496, name 'in:imuxsock'
0289.281860565:7fae9f2f3700: thread created, tid 32497, name 'in:imklog'
0289.281876152:7fae9f2f3700: set thread name to 'in:imklog'
0289.281930636:7fae9fcf4700: set thread name to 'in:imuxsock'
0289.281942251:main thread : started.
0289.281969315:imklog.c : imklog(BSD/Linux) waiting for kernel log line
0289.282071085:imfile.c : imfile: working in inotify mode
0289.282091310:main thread : main Q: qqueueAdd: entry added, size now log 1,
phys 1 entries
0289.282104823:imfile.c : imfile: inotify fd 5
0289.282125860:main thread : main Q:Reg: high activity - starting 1
additional worker thread(s).
0289.282140241:imfile.c : DDDD: imfile: enter into wdmap[0]: wd 1, dir 0,
file -1
0289.282149138:imfile.c : DDDD: watch 1 added for dir /var/log/modsec
0289.282166927:imfile.c : DDDD: imfile: enter into wdmap[1]: wd 2, dir
-1, file 0
0289.282171843:imfile.c : DDDD: watch 2 added for file
/var/log/modsec/audit.log
0289.282176170:imfile.c : DDDD: associated file
0[/var/log/modsec/audit.log] to directory 0[/var/log/modsec]
0289.282183179:main thread : main Q:Reg: started with state 0, num workers
now 1
0289.282195577:main thread : main Q: EnqueueMsg advised worker start
0289.282203850:main thread : Debugging enabled, SIGUSR1 to turn off
debugging.
0289.282210664:main thread : initialization completed, transitioning to
regular run mode
0289.282227156:imfile.c : filemon 0x12e3300: clean startup, no .si file
found
0289.282280146:imuxsock.c : --------imuxsock calling select, active file
descriptors (max 3): 3
0289.282306252:7fae9e8f2700: thread created, tid 32498, name 'rs:main Q:Reg'
0289.282317690:imfile.c : file stream /var/log/modsec/audit.log params:
flush interval 0, async write 0
0289.282346783:imuxsock.c :
0289.282371259:imfile.c : file '/var/log/modsec/audit.log' opened as #6
with mode 384
0289.282385538:imfile.c : strm 0x7fae90002130: opened file
'/var/log/modsec/audit.log' for READ as 6
0289.282392255:imfile.c : strm 0x7fae90002130: file 6 read 0 bytes
0289.282408996:imfile.c : stream checking for file change on
'/var/log/modsec/audit.log', inode 399759/399759
0289.282454784:main Q:Reg/w0 : wti 0x12e9a90: worker starting
0289.282471507:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 objects and
enqueued 0 objects
0289.282476757:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 1, phys 1
0289.282484576:main Q:Reg/w0 : processBATCH: batch of 1 elements must be
processed
0289.282488839:main Q:Reg/w0 : processBATCH: next msg 0: [origin
software="rsyslogd" swVersion="8.5.0" x-pid="32494"
x-info="http://www.rsyslog.com";] start
0289.282492895:main Q:Reg/w0 : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0289.282502282:main Q:Reg/w0 : executing action 0
0289.282507714:main Q:Reg/w0 : Called action, logging to builtin:omfile
0289.282519873:main Q:Reg/w0 : action 0 is transactional - executing in commit
phase
0289.282523865:main Q:Reg/w0 : wti 0x12e9a90: we need to create a new action
worker instance for action 0
0289.282528492:main Q:Reg/w0 : Action 0 transitioned to state: itx
0289.282532002:main Q:Reg/w0 : action completing - hit FINALIZE ACTION 1
[omrelp:action(type="omrelp" ...)]
0289.282543470:main Q:Reg/w0 : executing action 1
0289.282546744:main Q:Reg/w0 : Called action, logging to omrelp
0289.282551154:main Q:Reg/w0 : action 2 queue: Add to LL: [origin
software="rsyslogd" swVersion="8.5.0" x-pid="32494"
x-info="http://www.rsyslog.com";] start
0289.282555176:main Q:Reg/w0 : action 2 queue: qqueueAdd: entry added, size
now log 1, phys 1 entries
0289.282559208:main Q:Reg/w0 : action 2 queue:Reg: high activity - starting 1
additional worker thread(s).
0289.282602787:main Q:Reg/w0 : action 2 queue:Reg: started with state 0, num
workers now 1
0289.282609667:main Q:Reg/w0 : action 2 queue: EnqueueMsg advised worker start
0289.282620505:main Q:Reg/w0 : END batch execution phase, entering to commit
phase
0289.282631659:main Q:Reg/w0 : actionCommitAll: action 0, state 1, nbr to
commit 1 isTransactional 1
0289.282642150:main Q:Reg/w0 : doTransaction: have commitTransaction IF, using
that, pWrkrInfo 0x12e9b60
0289.282651566:main Q:Reg/w0 : entering actionCallCommitTransaction(), state:
itx, actionNbr 0, nMsgs 1
0289.282660423:7fae9def1700: thread created, tid 32499, name 'rs:action 2
queue:Reg'
0289.282697245:action 2 queue:Reg/w0: wti 0x12d7390: worker starting
0289.282712728:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 0
objects and enqueued 0 objects
0289.282722962:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 1, phys 1
0289.282733798:action 2 queue:Reg/w0: action 2 queue: Del from LL: [origin
software="rsyslogd" swVersion="8.5.0" x-pid="32494"
x-info="http://www.rsyslog.com";] start
0289.282746976:action 2 queue:Reg/w0: action 1 is transactional - executing in
commit phase
0289.282756835:action 2 queue:Reg/w0: wti 0x12d7390: we need to create a new
action worker instance for action 1
0289.282775251:action 2 queue:Reg/w0: relp engine created new client
0x7fae8c002340
0289.282786500:action 2 queue:Reg/w0: omrelp: beginTransaction
0289.282802046:main Q:Reg/w0 : file stream syslog params: flush interval 0,
async write 0
0289.282815329:main Q:Reg/w0 : lmsig_gt: onFileOpen: /var/log/syslog
0289.282876212:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fae880024a0, lenBuf 151, strt data 2014-09-03T10:31:29.281956+00:00 server
rsyslogd: [origin software="rsyslogd" swVersion="8.5.0" x-pid="32494"
x-info="http://w
0289.282883234:main Q:Reg/w0 : lmsig_gt: onRecordWrite (150):
2014-09-03T10:31:29.281956+00:00 server rsyslogd: [origin software="rsyslogd"
swVersion="8.5.0" x-pid="32494" x-info="http://www.rsyslog.com";] start
0289.283084566:main Q:Reg/w0 : strm 0x7fae880024a0: file -1(syslog) flush,
buflen 151
0289.283094959:main Q:Reg/w0 : strmPhysWrite, stream 0x7fae880024a0, len 151
0289.283110220:main Q:Reg/w0 : file '/var/log/syslog' opened as #7 with mode
420
0289.283118037:main Q:Reg/w0 : strm 0x7fae880024a0: opened file
'/var/log/syslog' for WRITE as 7
0289.283145680:main Q:Reg/w0 : strm 0x7fae880024a0: file 7 write wrote 151
bytes
0289.283151297:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0289.283161563:main Q:Reg/w0 : Action 0 transitioned to state: itx
0289.283166776:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0289.283175234:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0
0289.283179352:main Q:Reg/w0 : processBATCH: batch of 1 elements has been
processed
0289.283183275:main Q:Reg/w0 : regular consumer finished, iret=0, szlog 0 sz
phys 1
0289.283191702:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 objects and
enqueued 0 objects
0289.283195715:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 0, phys 0
0289.283199703:main Q:Reg/w0 : regular consumer finished, iret=4, szlog 0 sz
phys 0
0289.283203414:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting for work.
0289.284378160:action 2 queue:Reg/w0: frame to send: '1 open 85 relp_version=0
relp_software=librelp,1.2.5,http://librelp.adiscon.com
commands=syslog
'
0289.284413371:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 1,
sessState 1
0289.284423615:action 2 queue:Reg/w0: sendbuf added to unacked list
0289.284437491:action 2 queue:Reg/w0: relpSessWaitRsp waiting for data on fd 9,
timeout 90.0
0289.285165568:action 2 queue:Reg/w0: relpSessWaitRsp select returns, nfds 1,
errno 11
0289.285187944:action 2 queue:Reg/w0: relp session read 102 octets, buf '1 rsp
92 200 OK
relp_version=0
relp_software=librelp,1.2.5,http://librelp.adiscon.com
commands=syslog
'
0289.285195716:action 2 queue:Reg/w0: relp engine is dispatching frame with
command 'rsp'
0289.285202167:action 2 queue:Reg/w0: in rsp command handler, txnr 1, code 200,
text 'OK'
0289.285206995:action 2 queue:Reg/w0: DEL sess 0x7fae8c0023e0 unacked 0,
sessState 2
0289.285215027:action 2 queue:Reg/w0: processing server offer 'commands'
0289.285222245:action 2 queue:Reg/w0: SetEnableCmd in syslog cmd state: 3
0289.285229451:action 2 queue:Reg/w0: SetEnableCmd out syslog cmd state: 4,
iRet 0
0289.285235494:action 2 queue:Reg/w0: enabled command 'syslog'
0289.285241616:action 2 queue:Reg/w0: processing server offer 'relp_software'
0289.285247867:action 2 queue:Reg/w0: processing server offer 'relp_version'
0289.285255836:action 2 queue:Reg/w0: in destructor: sendbuf 0x7fae8c002970
0289.285263598:action 2 queue:Reg/w0: iRet after relpSessRcvData 0
0289.285269989:action 2 queue:Reg/w0: relpSessWaitState returns 0
0289.285276993:action 2 queue:Reg/w0: end relpSessConnect, iRet 0
0289.285288974:action 2 queue:Reg/w0: Action 1 transitioned to state: itx
0289.285296513:action 2 queue:Reg/w0: action completing - hit
FINALIZEdoTransaction: action 1, currIParam 1
0289.285310287:action 2 queue:Reg/w0: omrelp: shutdownImmediate ptr now is
0x12e2f30
0289.285315464:action 2 queue:Reg/w0: entering actionCalldoAction(), state:
itx, actionNbr 1
0289.285319540:action 2 queue:Reg/w0:
gb-logger.skyscape.preview-dvla.co.uk:514/RELP
0289.285324023:action 2 queue:Reg/w0: relpSessWaitState returns 0
0289.285329367:action 2 queue:Reg/w0: frame to send: '2 syslog 154
<46>2014-09-03T10:31:29.281956+00:00 server rsyslogd: [origin
software="rsyslogd" swVersion="8.5.0" x-pid="32494"
x-info="http://www.rsyslog.com";] start
'
0289.285337965:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 1,
sessState 4
0289.285341700:action 2 queue:Reg/w0: sendbuf added to unacked list
0289.285345487:action 2 queue:Reg/w0: omrelp: endTransaction
0289.285366498:action 2 queue:Reg/w0: Action 1 transitioned to state: rdy
0289.285376165:action 2 queue:Reg/w0: actionCommit, in retry loop, iRet 0
0289.285383054:action 2 queue:Reg/w0: regular consumer finished, iret=0, szlog
0 sz phys 1
0289.285402233:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 1
objects and enqueued 0 objects
0289.285408207:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 0, phys 0
0289.285412478:action 2 queue:Reg/w0: regular consumer finished, iret=4, szlog
0 sz phys 0
0289.285416177:action 2 queue:Reg/w0: action 2 queue:Reg/w0: worker IDLE,
waiting for work.
0296.924137625:imuxsock.c : Message from UNIX socket: #3
0296.924220605:imuxsock.c : main Q: qqueueAdd: entry added, size now log 1,
phys 1 entries
0296.924255762:imuxsock.c : main Q: EnqueueMsg advised worker start
0296.924285756:imuxsock.c : --------imuxsock calling select, active file
descriptors (max 3): 3
0296.924324906:main Q:Reg/w0 : wti 0x12e9a90: worker awoke from idle processing
0296.924334505:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 objects and
enqueued 0 objects
0296.924338815:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 1, phys 1
0296.924348222:main Q:Reg/w0 : processBATCH: batch of 1 elements must be
processed
0296.924353910:main Q:Reg/w0 : processBATCH: next msg 0: <13>Sep 3 10:31:36
user: HELLO WORLD
0296.924375906:main Q:Reg/w0 : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0296.924387269:main Q:Reg/w0 : executing action 0
0296.924394918:main Q:Reg/w0 : Called action, logging to builtin:omfile
0296.924420158:main Q:Reg/w0 : action 0 is transactional - executing in commit
phase
0296.924427108:main Q:Reg/w0 : Action 0 transitioned to state: itx
0296.924430686:main Q:Reg/w0 : action completing - hit FINALIZE ACTION 1
[omrelp:action(type="omrelp" ...)]
0296.924444555:main Q:Reg/w0 : executing action 1
0296.924451342:main Q:Reg/w0 : Called action, logging to omrelp
0296.924460034:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD
0296.924468366:main Q:Reg/w0 : action 2 queue: qqueueAdd: entry added, size
now log 1, phys 1 entries
0296.924488293:main Q:Reg/w0 : action 2 queue: EnqueueMsg advised worker start
0296.924498508:main Q:Reg/w0 : END batch execution phase, entering to commit
phase
0296.924506710:main Q:Reg/w0 : actionCommitAll: action 0, state 1, nbr to
commit 1 isTransactional 1
0296.924528245:main Q:Reg/w0 : doTransaction: have commitTransaction IF, using
that, pWrkrInfo 0x12e9b60
0296.924539984:main Q:Reg/w0 : entering actionCallCommitTransaction(), state:
itx, actionNbr 0, nMsgs 1
0296.924548544:action 2 queue:Reg/w0: wti 0x12d7390: worker awoke from idle
processing
0296.924572143:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 0
objects and enqueued 0 objects
0296.924581437:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 1, phys 1
0296.924590119:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
action 1 is transactional - executing in commit phase
0296.924609594:action 2 queue:Reg/w0: omrelp: beginTransaction
0296.924620572:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fae880024a0, lenBuf 62, strt data 2014-09-03T10:31:36.924194+00:00 server
user: HELLO WORLD
0296.924642280:action 2 queue:Reg/w0: Action 1 transitioned to state: itx
0296.924660182:action 2 queue:Reg/w0: action completing - hit
FINALIZEdoTransaction: action 1, currIParam 1
0296.924680358:action 2 queue:Reg/w0: omrelp: shutdownImmediate ptr now is
0x12e2f30
0296.924689304:action 2 queue:Reg/w0: entering actionCalldoAction(), state:
itx, actionNbr 1
0296.924694449:action 2 queue:Reg/w0:
gb-logger.skyscape.preview-dvla.co.uk:514/RELP
0296.924705404:action 2 queue:Reg/w0: relpSessWaitState returns 0
0296.924716524:action 2 queue:Reg/w0: frame to send: '3 syslog 65
<13>2014-09-03T10:31:36.924194+00:00 server user: HELLO WORLD
'
0296.924745943:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 2,
sessState 4
0296.924752810:action 2 queue:Reg/w0: sendbuf added to unacked list
0296.924757425:action 2 queue:Reg/w0: omrelp: endTransaction
0296.924781297:action 2 queue:Reg/w0: Action 1 transitioned to state: rdy
0296.924787566:action 2 queue:Reg/w0: actionCommit, in retry loop, iRet 0
0296.924802756:action 2 queue:Reg/w0: regular consumer finished, iret=0, szlog
0 sz phys 1
0296.924808052:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 1
objects and enqueued 0 objects
0296.924812273:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 0, phys 0
0296.924816279:action 2 queue:Reg/w0: regular consumer finished, iret=4, szlog
0 sz phys 0
0296.924820238:action 2 queue:Reg/w0: action 2 queue:Reg/w0: worker IDLE,
waiting for work.
0296.924935587:main Q:Reg/w0 : lmsig_gt: onRecordWrite (61):
2014-09-03T10:31:36.924194+00:00 server user: HELLO WORLD
0296.924990499:main Q:Reg/w0 : strm 0x7fae880024a0: file 7(syslog) flush,
buflen 62
0296.925000357:main Q:Reg/w0 : strmPhysWrite, stream 0x7fae880024a0, len 62
0296.925015965:main Q:Reg/w0 : strm 0x7fae880024a0: file 7 write wrote 62 bytes
0296.925020675:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0296.925024696:main Q:Reg/w0 : Action 0 transitioned to state: itx
0296.925028332:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0296.925031724:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0
0296.925035230:main Q:Reg/w0 : processBATCH: batch of 1 elements has been
processed
0296.925039354:main Q:Reg/w0 : regular consumer finished, iret=0, szlog 0 sz
phys 1
0296.925045076:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 objects and
enqueued 0 objects
0296.925048946:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 0, phys 0
0296.925052856:main Q:Reg/w0 : regular consumer finished, iret=4, szlog 0 sz
phys 0
0296.925056410:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting for work.
0304.004796170:imuxsock.c : Message from UNIX socket: #3
0304.004838030:imuxsock.c : main Q: qqueueAdd: entry added, size now log 1,
phys 1 entries
0304.004849818:imuxsock.c : main Q: EnqueueMsg advised worker start
0304.004856061:imuxsock.c : --------imuxsock calling select, active file
descriptors (max 3): 3
0304.004872580:main Q:Reg/w0 : wti 0x12e9a90: worker awoke from idle processing
0304.004880253:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 objects and
enqueued 0 objects
0304.004884273:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 1, phys 1
0304.004890407:main Q:Reg/w0 : processBATCH: batch of 1 elements must be
processed
0304.004894828:main Q:Reg/w0 : processBATCH: next msg 0: <13>Sep 3 10:31:44
user: HELLO WORLD AAA
0304.004899961:main Q:Reg/w0 : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0304.004911324:main Q:Reg/w0 : executing action 0
0304.004916209:main Q:Reg/w0 : Called action, logging to builtin:omfile
0304.004925788:main Q:Reg/w0 : action 0 is transactional - executing in commit
phase
0304.004931735:main Q:Reg/w0 : Action 0 transitioned to state: itx
0304.004936095:main Q:Reg/w0 : action completing - hit FINALIZE ACTION 1
[omrelp:action(type="omrelp" ...)]
0304.004949414:main Q:Reg/w0 : executing action 1
0304.004952802:main Q:Reg/w0 : Called action, logging to omrelp
0304.004957866:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD AAA
0304.004962113:main Q:Reg/w0 : action 2 queue: qqueueAdd: entry added, size
now log 1, phys 1 entries
0304.004981973:main Q:Reg/w0 : action 2 queue: EnqueueMsg advised worker start
0304.004988072:main Q:Reg/w0 : END batch execution phase, entering to commit
phase
0304.004992554:main Q:Reg/w0 : actionCommitAll: action 0, state 1, nbr to
commit 1 isTransactional 1
0304.004996872:main Q:Reg/w0 : doTransaction: have commitTransaction IF, using
that, pWrkrInfo 0x12e9b60
0304.005002449:main Q:Reg/w0 : entering actionCallCommitTransaction(), state:
itx, actionNbr 0, nMsgs 1
0304.005015425:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fae880024a0, lenBuf 66, strt data 2014-09-03T10:31:44.004823+00:00 server
user: HELLO WORLD AAA
0304.005026923:main Q:Reg/w0 : lmsig_gt: onRecordWrite (65):
2014-09-03T10:31:44.004823+00:00 server user: HELLO WORLD AAA
0304.005046715:action 2 queue:Reg/w0: wti 0x12d7390: worker awoke from idle
processing
0304.005079631:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 0
objects and enqueued 0 objects
0304.005085425:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 1, phys 1
0304.005094611:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
AAA
&
0304.005108458:main Q:Reg/w0 : strm 0x7fae880024a0: file 7(syslog) flush,
buflen 66
0304.005118410:main Q:Reg/w0 : strmPhysWrite, stream 0x7fae880024a0, len 66
0304.005137040:action 2 queue:Reg/w0: action 1 is transactional - executing in
commit phase
0304.005150226:action 2 queue:Reg/w0: omrelp: beginTransaction
0304.005163197:main Q:Reg/w0 : strm 0x7fae880024a0: file 7 write wrote 66 bytes
0304.005178702:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0304.005187587:main Q:Reg/w0 : Action 0 transitioned to state: itx
0304.005205290:action 2 queue:Reg/w0: Action 1 transitioned to state: itx
0304.005217554:action 2 queue:Reg/w0: action completing - hit
FINALIZEdoTransaction: action 1, currIParam 1
0304.005227083:action 2 queue:Reg/w0: omrelp: shutdownImmediate ptr now is
0x12e2f30
0304.005231167:action 2 queue:Reg/w0: entering actionCalldoAction(), state:
itx, actionNbr 1
0304.005235234:action 2 queue:Reg/w0:
gb-logger.skyscape.preview-dvla.co.uk:514/RELP
0304.005243388:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0304.005257584:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0
0304.005264160:main Q:Reg/w0 : processBATCH: batch of 1 elements has been
processed
0304.005273636:main Q:Reg/w0 : regular consumer finished, iret=0, szlog 0 sz
phys 1
0304.005285173:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 objects and
enqueued 0 objects
0304.005295539:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 0, phys 0
0304.005308314:main Q:Reg/w0 : regular consumer finished, iret=4, szlog 0 sz
phys 0
0304.005318579:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting for work.
0304.005327624:action 2 queue:Reg/w0: relpSessWaitState returns 0
0304.005340021:action 2 queue:Reg/w0: frame to send: '4 syslog 69
<13>2014-09-03T10:31:44.004823+00:00 server user: HELLO WORLD AAA
'
0304.005351448:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 3,
sessState 4
0304.005355658:action 2 queue:Reg/w0: sendbuf added to unacked list
0304.005359866:action 2 queue:Reg/w0: omrelp: endTransaction
0304.005383740:action 2 queue:Reg/w0: Action 1 transitioned to state: rdy
0304.005390963:action 2 queue:Reg/w0: actionCommit, in retry loop, iRet 0
0304.005395175:action 2 queue:Reg/w0: regular consumer finished, iret=0, szlog
0 sz phys 1
0304.005401426:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 1
objects and enqueued 0 objects
0304.005405552:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 0, phys 0
0304.005409669:action 2 queue:Reg/w0: regular consumer finished, iret=4, szlog
0 sz phys 0
0304.005413509:action 2 queue:Reg/w0: action 2 queue:Reg/w0: worker IDLE,
waiting for work.
0305.887826185:imuxsock.c : Message from UNIX socket: #3
0305.887863526:imuxsock.c : main Q: qqueueAdd: entry added, size now log 1,
phys 1 entries
0305.887883059:imuxsock.c : main Q: EnqueueMsg advised worker start
0305.887890672:imuxsock.c : --------imuxsock calling select, active file
descriptors (max 3): 3
0305.887903376:main Q:Reg/w0 : wti 0x12e9a90: worker awoke from idle processing
0305.887921523:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 objects and
enqueued 0 objects
0305.887926356:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 1, phys 1
0305.887932941:main Q:Reg/w0 : processBATCH: batch of 1 elements must be
processed
0305.887937351:main Q:Reg/w0 : processBATCH: next msg 0: <13>Sep 3 10:31:45
user: HELLO WORLD BBB
0305.887942583:main Q:Reg/w0 : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0305.887953242:main Q:Reg/w0 : executing action 0
0305.887957141:main Q:Reg/w0 : Called action, logging to builtin:omfile
0305.887965541:main Q:Reg/w0 : action 0 is transactional - executing in commit
phase
0305.887980306:main Q:Reg/w0 : Action 0 transitioned to state: itx
0305.887984094:main Q:Reg/w0 : action completing - hit FINALIZE ACTION 1
[omrelp:action(type="omrelp" ...)]
0305.887996756:main Q:Reg/w0 : executing action 1
0305.888000082:main Q:Reg/w0 : Called action, logging to omrelp
0305.888005537:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD BBB
0305.888009743:main Q:Reg/w0 : action 2 queue: qqueueAdd: entry added, size
now log 1, phys 1 entries
0305.888017659:main Q:Reg/w0 : action 2 queue: EnqueueMsg advised worker start
0305.888021783:main Q:Reg/w0 : END batch execution phase, entering to commit
phase
0305.888026305:main Q:Reg/w0 : actionCommitAll: action 0, state 1, nbr to
commit 1 isTransactional 1
0305.888030424:main Q:Reg/w0 : doTransaction: have commitTransaction IF, using
that, pWrkrInfo 0x12e9b60
0305.888034206:main Q:Reg/w0 : entering actionCallCommitTransaction(), state:
itx, actionNbr 0, nMsgs 1
0305.888039089:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fae880024a0, lenBuf 66, strt data 2014-09-03T10:31:45.887849+00:00 server
user: HELLO WORLD BBB
0305.888044182:main Q:Reg/w0 : lmsig_gt: onRecordWrite (65):
2014-09-03T10:31:45.887849+00:00 server user: HELLO WORLD BBB
0305.888070631:main Q:Reg/w0 : strm 0x7fae880024a0: file 7(syslog) flush,
buflen 66
0305.888076892:main Q:Reg/w0 : strmPhysWrite, stream 0x7fae880024a0, len 66
0305.888087446:main Q:Reg/w0 : strm 0x7fae880024a0: file 7 write wrote 66 bytes
0305.888091960:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0305.888095870:main Q:Reg/w0 : Action 0 transitioned to state: itx
0305.888099476:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0305.888102932:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0
0305.888106423:main Q:Reg/w0 : processBATCH: batch of 1 elements has been
processed
0305.888110187:main Q:Reg/w0 : regular consumer finished, iret=0, szlog 0 sz
phys 1
0305.888114328:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 objects and
enqueued 0 objects
0305.888117813:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 0, phys 0
0305.888121623:main Q:Reg/w0 : regular consumer finished, iret=4, szlog 0 sz
phys 0
0305.888125305:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting for work.
0305.888138814:action 2 queue:Reg/w0: wti 0x12d7390: worker awoke from idle
processing
0305.888150134:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 0
objects and enqueued 0 objects
0305.888157739:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 1, phys 1
0305.888165880:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
BBB
0305.888178939:action 2 queue:Reg/w0: action 1 is transactional - executing in
commit phase
0305.888185913:action 2 queue:Reg/w0: omrelp: beginTransaction
0305.888195676:action 2 queue:Reg/w0: Action 1 transitioned to state: itx
0305.888199261:action 2 queue:Reg/w0: action completing - hit
FINALIZEdoTransaction: action 1, currIParam 1
0305.888206627:action 2 queue:Reg/w0: omrelp: shutdownImmediate ptr now is
0x12e2f30
0305.888210680:action 2 queue:Reg/w0: entering actionCalldoAction(), state:
itx, actionNbr 1
0305.888214651:action 2 queue:Reg/w0:
gb-logger.skyscape.preview-dvla.co.uk:514/RELP
0305.888220885:action 2 queue:Reg/w0: relpSessWaitState returns 0
0305.888227501:action 2 queue:Reg/w0: frame to send: '5 syslog 69
<13>2014-09-03T10:31:45.887849+00:00 server user: HELLO WORLD BBB
'
0305.888236891:action 2 queue:Reg/w0: relp session 0x7fae8c0023e0 flagged as
broken, IO error
0305.888240810:action 2 queue:Reg/w0: error forwarding via relp, suspending
0305.888244718:action 2 queue:Reg/w0: Action 1 transitioned to state: rtry
0305.888248876:action 2 queue:Reg/w0: actionDoRetry: action 2 enter loop,
iRetries=0
0305.889029161:action 2 queue:Reg/w0: end relpSessConnect, iRet 10014
0305.889039887:action 2 queue:Reg/w0: after TryReestablish, sess state 9
0305.889044178:action 2 queue:Reg/w0: actionDoRetry: action 2 action->tryResume
returned -2007
0305.889048237:action 2 queue:Reg/w0: actionDoRetry: action 2 check for max
retries, iResumeRetryCount 10, iRetries 0
0308.064027203:imuxsock.c : Message from UNIX socket: #3
0308.064066118:imuxsock.c : main Q: qqueueAdd: entry added, size now log 1,
phys 1 entries
0308.064077923:imuxsock.c : main Q: EnqueueMsg advised worker start
0308.064083822:imuxsock.c : --------imuxsock calling select, active file
descriptors (max 3): 3
0308.064103096:main Q:Reg/w0 : wti 0x12e9a90: worker awoke from idle processing
0308.064115199:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 objects and
enqueued 0 objects
0308.064124906:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 1, phys 1
0308.064137289:main Q:Reg/w0 : processBATCH: batch of 1 elements must be
processed
0308.064144625:main Q:Reg/w0 : processBATCH: next msg 0: <13>Sep 3 10:31:48
user: HELLO WORLD CCC
0308.064149888:main Q:Reg/w0 : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0308.064160445:main Q:Reg/w0 : executing action 0
0308.064164569:main Q:Reg/w0 : Called action, logging to builtin:omfile
0308.064173091:main Q:Reg/w0 : action 0 is transactional - executing in commit
phase
0308.064177943:main Q:Reg/w0 : Action 0 transitioned to state: itx
0308.064181355:main Q:Reg/w0 : action completing - hit FINALIZE ACTION 1
[omrelp:action(type="omrelp" ...)]
0308.064193394:main Q:Reg/w0 : executing action 1
0308.064196739:main Q:Reg/w0 : Called action, logging to omrelp
0308.064202433:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD CCC
0308.064206775:main Q:Reg/w0 : action 2 queue: qqueueAdd: entry added, size
now log 1, phys 2 entries
0308.064211150:main Q:Reg/w0 : action 2 queue: EnqueueMsg advised worker start
0308.064214800:main Q:Reg/w0 : END batch execution phase, entering to commit
phase
0308.064218843:main Q:Reg/w0 : actionCommitAll: action 0, state 1, nbr to
commit 1 isTransactional 1
0308.064222872:main Q:Reg/w0 : doTransaction: have commitTransaction IF, using
that, pWrkrInfo 0x12e9b60
0308.064226718:main Q:Reg/w0 : entering actionCallCommitTransaction(), state:
itx, actionNbr 0, nMsgs 1
0308.064231698:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fae880024a0, lenBuf 66, strt data 2014-09-03T10:31:48.064051+00:00 server
user: HELLO WORLD CCC
0308.064237082:main Q:Reg/w0 : lmsig_gt: onRecordWrite (65):
2014-09-03T10:31:48.064051+00:00 server user: HELLO WORLD CCC
0308.064259867:main Q:Reg/w0 : strm 0x7fae880024a0: file 7(syslog) flush,
buflen 66
0308.064265515:main Q:Reg/w0 : strmPhysWrite, stream 0x7fae880024a0, len 66
0308.064275983:main Q:Reg/w0 : strm 0x7fae880024a0: file 7 write wrote 66 bytes
0308.064280716:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0308.064284542:main Q:Reg/w0 : Action 0 transitioned to state: itx
0308.064288286:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0308.064291825:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0
0308.064297050:main Q:Reg/w0 : processBATCH: batch of 1 elements has been
processed
0308.064301021:main Q:Reg/w0 : regular consumer finished, iret=0, szlog 0 sz
phys 1
0308.064305341:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 objects and
enqueued 0 objects
0308.064309051:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 0, phys 0
0308.064312865:main Q:Reg/w0 : regular consumer finished, iret=4, szlog 0 sz
phys 0
0308.064316823:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting for work.
0309.806779811:imuxsock.c : Message from UNIX socket: #3
0309.806818972:imuxsock.c : main Q: qqueueAdd: entry added, size now log 1,
phys 1 entries
0309.806838440:imuxsock.c : main Q: EnqueueMsg advised worker start
0309.806845482:imuxsock.c : --------imuxsock calling select, active file
descriptors (max 3): 3
0309.806862764:main Q:Reg/w0 : wti 0x12e9a90: worker awoke from idle processing
0309.806882085:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 objects and
enqueued 0 objects
0309.806891237:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 1, phys 1
0309.806914289:main Q:Reg/w0 : processBATCH: batch of 1 elements must be
processed
0309.806920209:main Q:Reg/w0 : processBATCH: next msg 0: <13>Sep 3 10:31:49
user: HELLO WORLD DDD
0309.806926019:main Q:Reg/w0 : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0309.806936514:main Q:Reg/w0 : executing action 0
0309.806940841:main Q:Reg/w0 : Called action, logging to builtin:omfile
0309.806950087:main Q:Reg/w0 : action 0 is transactional - executing in commit
phase
0309.806954817:main Q:Reg/w0 : Action 0 transitioned to state: itx
0309.806958205:main Q:Reg/w0 : action completing - hit FINALIZE ACTION 1
[omrelp:action(type="omrelp" ...)]
0309.806970405:main Q:Reg/w0 : executing action 1
0309.806973741:main Q:Reg/w0 : Called action, logging to omrelp
0309.806979297:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD DDD
0309.806983703:main Q:Reg/w0 : action 2 queue: qqueueAdd: entry added, size
now log 2, phys 3 entries
0309.806988088:main Q:Reg/w0 : action 2 queue: EnqueueMsg advised worker start
0309.806991722:main Q:Reg/w0 : END batch execution phase, entering to commit
phase
0309.806995652:main Q:Reg/w0 : actionCommitAll: action 0, state 1, nbr to
commit 1 isTransactional 1
0309.806999797:main Q:Reg/w0 : doTransaction: have commitTransaction IF, using
that, pWrkrInfo 0x12e9b60
0309.807003680:main Q:Reg/w0 : entering actionCallCommitTransaction(), state:
itx, actionNbr 0, nMsgs 1
0309.807008612:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fae880024a0, lenBuf 66, strt data 2014-09-03T10:31:49.806803+00:00 server
user: HELLO WORLD DDD
0309.807015985:main Q:Reg/w0 : lmsig_gt: onRecordWrite (65):
2014-09-03T10:31:49.806803+00:00 server user: HELLO WORLD DDD
0309.807068171:main Q:Reg/w0 : strm 0x7fae880024a0: file 7(syslog) flush,
buflen 66
0309.807076368:main Q:Reg/w0 : strmPhysWrite, stream 0x7fae880024a0, len 66
0309.807088325:main Q:Reg/w0 : strm 0x7fae880024a0: file 7 write wrote 66 bytes
0309.807092824:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0309.807096860:main Q:Reg/w0 : Action 0 transitioned to state: itx
0309.807100575:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0309.807103882:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0
0309.807107313:main Q:Reg/w0 : processBATCH: batch of 1 elements has been
processed
0309.807111340:main Q:Reg/w0 : regular consumer finished, iret=0, szlog 0 sz
phys 1
0309.807115511:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 objects and
enqueued 0 objects
0309.807119242:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 0, phys 0
0309.807123009:main Q:Reg/w0 : regular consumer finished, iret=4, szlog 0 sz
phys 0
0309.807126845:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting for work.
0310.863781437:imuxsock.c : Message from UNIX socket: #3
0310.863818206:imuxsock.c : main Q: qqueueAdd: entry added, size now log 1,
phys 1 entries
0310.863829563:imuxsock.c : main Q: EnqueueMsg advised worker start
0310.863835450:imuxsock.c : --------imuxsock calling select, active file
descriptors (max 3): 3
0310.863864061:main Q:Reg/w0 : wti 0x12e9a90: worker awoke from idle processing
0310.863873328:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 objects and
enqueued 0 objects
0310.863877376:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 1, phys 1
0310.863883625:main Q:Reg/w0 : processBATCH: batch of 1 elements must be
processed
0310.863888030:main Q:Reg/w0 : processBATCH: next msg 0: <13>Sep 3 10:31:50
user: HELLO WORLD
0310.863892932:main Q:Reg/w0 : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0310.863903228:main Q:Reg/w0 : executing action 0
0310.863907318:main Q:Reg/w0 : Called action, logging to builtin:omfile
0310.863915570:main Q:Reg/w0 : action 0 is transactional - executing in commit
phase
0310.863920710:main Q:Reg/w0 : Action 0 transitioned to state: itx
0310.863924180:main Q:Reg/w0 : action completing - hit FINALIZE ACTION 1
[omrelp:action(type="omrelp" ...)]
0310.863936502:main Q:Reg/w0 : executing action 1
0310.863951219:main Q:Reg/w0 : Called action, logging to omrelp
0310.863961543:main Q:Reg/w0 : action 2 queue: Add to LL: HELLO WORLD
0310.864015813:main Q:Reg/w0 : action 2 queue: qqueueAdd: entry added, size
now log 3, phys 4 entries
0310.864021204:main Q:Reg/w0 : action 2 queue: EnqueueMsg advised worker start
0310.864025451:main Q:Reg/w0 : END batch execution phase, entering to commit
phase
0310.864029829:main Q:Reg/w0 : actionCommitAll: action 0, state 1, nbr to
commit 1 isTransactional 1
0310.864034227:main Q:Reg/w0 : doTransaction: have commitTransaction IF, using
that, pWrkrInfo 0x12e9b60
0310.864038159:main Q:Reg/w0 : entering actionCallCommitTransaction(), state:
itx, actionNbr 0, nMsgs 1
0310.864043183:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fae880024a0, lenBuf 62, strt data 2014-09-03T10:31:50.863803+00:00 server
user: HELLO WORLD
0310.864048303:main Q:Reg/w0 : lmsig_gt: onRecordWrite (61):
2014-09-03T10:31:50.863803+00:00 server user: HELLO WORLD
0310.864077761:main Q:Reg/w0 : strm 0x7fae880024a0: file 7(syslog) flush,
buflen 62
0310.864090100:main Q:Reg/w0 : strmPhysWrite, stream 0x7fae880024a0, len 62
0310.864109381:main Q:Reg/w0 : strm 0x7fae880024a0: file 7 write wrote 62 bytes
0310.864114839:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0310.864120473:main Q:Reg/w0 : Action 0 transitioned to state: itx
0310.864124322:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0310.864130248:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0
0310.864137120:main Q:Reg/w0 : processBATCH: batch of 1 elements has been
processed
0310.864143864:main Q:Reg/w0 : regular consumer finished, iret=0, szlog 0 sz
phys 1
0310.864150758:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 1 objects and
enqueued 0 objects
0310.864154627:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 0, phys 0
0310.864158603:main Q:Reg/w0 : regular consumer finished, iret=4, szlog 0 sz
phys 0
0310.864163108:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting for work.
0310.894099394:action 2 queue:Reg/w0: actionDoRetry: action 2 enter loop,
iRetries=1
0310.894876770:action 2 queue:Reg/w0: end relpSessConnect, iRet 10014
0310.894887255:action 2 queue:Reg/w0: after TryReestablish, sess state 9
0310.894891714:action 2 queue:Reg/w0: actionDoRetry: action 2 action->tryResume
returned -2007
0310.894896037:action 2 queue:Reg/w0: actionDoRetry: action 2 check for max
retries, iResumeRetryCount 10, iRetries 1
0315.899956592:action 2 queue:Reg/w0: actionDoRetry: action 2 enter loop,
iRetries=2
0315.900845210:action 2 queue:Reg/w0: frame to send: '1 open 85 relp_version=0
relp_software=librelp,1.2.5,http://librelp.adiscon.com
commands=syslog
'
0315.900876913:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 4,
sessState 1
0315.900890209:action 2 queue:Reg/w0: sendbuf added to unacked list
0315.900903407:action 2 queue:Reg/w0: relpSessWaitRsp waiting for data on fd 9,
timeout 90.0
0315.901871535:action 2 queue:Reg/w0: relpSessWaitRsp select returns, nfds 1,
errno 11
0315.901887008:action 2 queue:Reg/w0: relp session read 102 octets, buf '1 rsp
92 200 OK
relp_version=0
relp_software=librelp,1.2.5,http://librelp.adiscon.com
commands=syslog
'
0315.901893914:action 2 queue:Reg/w0: relp engine is dispatching frame with
command 'rsp'
0315.901899149:action 2 queue:Reg/w0: in rsp command handler, txnr 1, code 200,
text 'OK'
0315.901904349:action 2 queue:Reg/w0: DEL sess 0x7fae8c0023e0 unacked 3,
sessState 2
0315.901916272:action 2 queue:Reg/w0: processing server offer 'commands'
0315.901921450:action 2 queue:Reg/w0: SetEnableCmd in syslog cmd state: 4
0315.901925343:action 2 queue:Reg/w0: SetEnableCmd out syslog cmd state: 4,
iRet 0
0315.901928925:action 2 queue:Reg/w0: enabled command 'syslog'
0315.901932395:action 2 queue:Reg/w0: processing server offer 'relp_software'
0315.901935881:action 2 queue:Reg/w0: processing server offer 'relp_version'
0315.901940978:action 2 queue:Reg/w0: in destructor: sendbuf 0x7fae8c003840
0315.901944981:action 2 queue:Reg/w0: iRet after relpSessRcvData 0
0315.901973617:action 2 queue:Reg/w0: relpSessWaitState returns 0
0315.901978501:action 2 queue:Reg/w0: end relpSessConnect, iRet 0
0315.901983039:action 2 queue:Reg/w0: relp session 0x7fae8c0023e0
reestablished, now resending 3 unacked frames
0315.901986916:action 2 queue:Reg/w0: resending frame '2 syslog 154
<46>2014-09-03T10:31:29.281956+00:00 server rsyslogd: [origin
software="rsyslogd" swVersion="8.5.0" x-pid="32494"
x-info="http://www.rsyslog.com";] start
'
0315.902005829:action 2 queue:Reg/w0: sendbuf NOT added to unacked list
0315.902019485:action 2 queue:Reg/w0: resending frame '3 syslog 65
<13>2014-09-03T10:31:36.924194+00:00 server user: HELLO WORLD
'
0315.902026662:action 2 queue:Reg/w0: sendbuf NOT added to unacked list
0315.902030677:action 2 queue:Reg/w0: resending frame '4 syslog 69
<13>2014-09-03T10:31:44.004823+00:00 server user: HELLO WORLD AAA
'
0315.902035715:action 2 queue:Reg/w0: sendbuf NOT added to unacked list
0315.902039531:action 2 queue:Reg/w0: after TryReestablish, sess state 4
0315.902043390:action 2 queue:Reg/w0: actionDoRetry: action 2 action->tryResume
returned 0
0315.902047124:action 2 queue:Reg/w0: actionDoRetry: action 2 had success RDY
again (iRet=0)
0315.902058601:action 2 queue:Reg/w0: Called LogMsg, msg: action 'action 2'
resumed (module 'omrelp')
0315.902083819:action 2 queue:Reg/w0: main Q: qqueueAdd: entry added, size now
log 1, phys 1 entries
0315.902095316:action 2 queue:Reg/w0: main Q: EnqueueMsg advised worker start
0315.902100892:action 2 queue:Reg/w0: Action 1 transitioned to state: rdy
0315.902108633:action 2 queue:Reg/w0: omrelp: beginTransaction
0315.902120842:action 2 queue:Reg/w0: Action 1 transitioned to state: itx
0315.902128651:action 2 queue:Reg/w0: omrelp: endTransaction
0315.902138275:action 2 queue:Reg/w0: Action 1 transitioned to state: rdy
0315.902145175:action 2 queue:Reg/w0: actionCommit, in retry loop, iRet 0
0315.902154052:action 2 queue:Reg/w0: regular consumer finished, iret=0, szlog
3 sz phys 4
0315.902166384:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 1
objects and enqueued 0 objects
0315.902172645:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 3, phys 3
0315.902177647:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
CCC
7Del from LL: HELLO WORLD DDD
0315.902185396:action 2 queue:Reg/w0: action 2 queue: Del from LL: HELLO WORLD
DDD
0315.902193714:action 2 queue:Reg/w0: action 1 is transactional - executing in
commit phase
0315.902197628:action 2 queue:Reg/w0: omrelp: beginTransaction
0315.902203146:action 2 queue:Reg/w0: Action 1 transitioned to state: itx
0315.902206558:action 2 queue:Reg/w0: action completing - hit FINALIZEaction 1
is transactional - executing in commit phase
0315.902216130:action 2 queue:Reg/w0: action completing - hit FINALIZEaction 1
is transactional - executing in commit phase
0315.902223782:action 2 queue:Reg/w0: action completing - hit
FINALIZEdoTransaction: action 1, currIParam 3
0315.902231581:action 2 queue:Reg/w0: omrelp: shutdownImmediate ptr now is
0x12e2f30
0315.902235392:action 2 queue:Reg/w0: entering actionCalldoAction(), state:
itx, actionNbr 1
0315.902239189:action 2 queue:Reg/w0:
gb-logger.skyscape.preview-dvla.co.uk:514/RELP
0315.902243402:action 2 queue:Reg/w0: relpSessWaitState returns 0
0315.902248285:action 2 queue:Reg/w0: frame to send: '5 syslog 69
<13>2014-09-03T10:31:48.064051+00:00 server user: HELLO WORLD CCC
'
0315.902254595:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 4,
sessState 4
0315.902258322:action 2 queue:Reg/w0: sendbuf added to unacked list
0315.902262816:action 2 queue:Reg/w0: Called LogMsg, msg: action 'action 2'
resumed (module 'omrelp')
0315.902270566:action 2 queue:Reg/w0: main Q: qqueueAdd: entry added, size now
log 2, phys 2 entries
0315.902275132:action 2 queue:Reg/w0: main Q: EnqueueMsg advised worker start
0315.902279311:action 2 queue:Reg/w0: omrelp: shutdownImmediate ptr now is
0x12e2f30
0315.902282815:action 2 queue:Reg/w0: entering actionCalldoAction(), state:
itx, actionNbr 1
0315.902292274:action 2 queue:Reg/w0:
gb-logger.skyscape.preview-dvla.co.uk:514/RELP
0315.902296089:action 2 queue:Reg/w0: relpSessWaitState returns 0
0315.902300329:action 2 queue:Reg/w0: frame to send: '6 syslog 69
<13>2014-09-03T10:31:49.806803+00:00 server user: HELLO WORLD DDD
'
0315.902306029:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 5,
sessState 4
0315.902314134:action 2 queue:Reg/w0: sendbuf added to unacked list
0315.902319493:action 2 queue:Reg/w0: omrelp: shutdownImmediate ptr now is
0x12e2f30
0315.902323183:action 2 queue:Reg/w0: entering actionCalldoAction(), state:
itx, actionNbr 1
0315.902326604:action 2 queue:Reg/w0:
gb-logger.skyscape.preview-dvla.co.uk:514/RELP
0315.902330105:action 2 queue:Reg/w0: relpSessWaitState returns 0
0315.902334446:action 2 queue:Reg/w0: frame to send: '7 syslog 65
<13>2014-09-03T10:31:50.863803+00:00 server user: HELLO WORLD
'
0315.902339917:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 6,
sessState 4
0315.902343413:action 2 queue:Reg/w0: sendbuf added to unacked list
0315.902347158:action 2 queue:Reg/w0: omrelp: endTransaction
0315.902352133:action 2 queue:Reg/w0: Action 1 transitioned to state: rdy
0315.902382338:action 2 queue:Reg/w0: actionCommit, in retry loop, iRet 0
0315.902389344:action 2 queue:Reg/w0: regular consumer finished, iret=0, szlog
0 sz phys 3
0315.902395129:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 3
objects and enqueued 0 objects
0315.902399237:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 0, phys 0
0315.902403350:action 2 queue:Reg/w0: regular consumer finished, iret=4, szlog
0 sz phys 0
0315.902407569:action 2 queue:Reg/w0: action 2 queue:Reg/w0: worker IDLE,
waiting for work.
0315.902422210:main Q:Reg/w0 : wti 0x12e9a90: worker awoke from idle processing
0315.902441156:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 objects and
enqueued 0 objects
0315.902446196:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 2, phys 2
0315.902453489:main Q:Reg/w0 : processBATCH: batch of 2 elements must be
processed
0315.902457685:main Q:Reg/w0 : processBATCH: next msg 0: action 'action 2'
resumed (module 'omrelp') [try http://www.rsyslog.com/e/0 ]
0315.902462814:main Q:Reg/w0 : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0315.902474414:main Q:Reg/w0 : executing action 0
0315.902478013:main Q:Reg/w0 : Called action, logging to builtin:omfile
0315.902484616:main Q:Reg/w0 : action 0 is transactional - executing in commit
phase
0315.902488795:main Q:Reg/w0 : Action 0 transitioned to state: itx
0315.902492149:main Q:Reg/w0 : action completing - hit FINALIZE ACTION 1
[omrelp:action(type="omrelp" ...)]
0315.902503789:main Q:Reg/w0 : executing action 1
0315.902507030:main Q:Reg/w0 : Called action, logging to omrelp
0315.902512068:main Q:Reg/w0 : action 2 queue: Add to LL: action 'action 2'
resumed (module 'omrelp') [try http://www.rsyslog.com/e/0 ]
0315.902516473:main Q:Reg/w0 : action 2 queue: qqueueAdd: entry added, size
now log 1, phys 1 entries
0315.902526824:main Q:Reg/w0 : action 2 queue: EnqueueMsg advised worker start
0315.902532024:main Q:Reg/w0 : processBATCH: next msg 1: action 'action 2'
resumed (module 'omrelp') [try http://www.rsyslog.com/e/2359 ]
0315.902535578:main Q:Reg/w0 : ACTION 0
[builtin:omfile:action(type="builtin:omfile" ...)]
0315.902544805:main Q:Reg/w0 : executing action 0
0315.902548217:main Q:Reg/w0 : Called action, logging to builtin:omfile
0315.902553430:action 2 queue:Reg/w0: wti 0x12d7390: worker awoke from idle
processing
0315.902570996:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 0
objects and enqueued 0 objects
0315.902588557:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 1, phys 1
0315.902609170:action 2 queue:Reg/w0: action 2 queue: Del from LL: action
'action 2' resumed (module 'omrelp') [try http://www.rsyslog.com/e/0 ]
0315.902624200:action 2 queue:Reg/w0: action 1 is transactional - executing in
commit phase
0315.902640133:action 2 queue:Reg/w0: omrelp: beginTransaction
0315.902672145:action 2 queue:Reg/w0: Action 1 transitioned to state: itx
0315.902686492:action 2 queue:Reg/w0: action completing - hit FINALIZE
0315.902693672:main Q:Reg/w0 : action 0 is transactional - executing in commit
phase
0315.902708742:main Q:Reg/w0 : action completing - hit FINALIZE
0315.902727625:action 2 queue:Reg/w0: doTransaction: action 1, currIParam 1
0315.902741572:action 2 queue:Reg/w0: omrelp: shutdownImmediate ptr now is
0x12e2f30
0315.902746785:action 2 queue:Reg/w0: entering actionCalldoAction(), state:
itx, actionNbr 1
0315.902759532:action 2 queue:Reg/w0:
gb-logger.skyscape.preview-dvla.co.uk:514/RELP
0315.902777941:action 2 queue:Reg/w0: relpSessWaitState returns 0
0315.902795143:action 2 queue:Reg/w0: frame to send: '8 syslog 134
<46>2014-09-03T10:31:55.902066+00:00 server rsyslogd0: action 'action 2'
resumed (module 'omrelp') [try http://www.rsyslog.com/e/0 ]
'
0315.902807533:main Q:Reg/w0 : ACTION 1 [omrelp:action(type="omrelp" ...)]
0315.902820606:main Q:Reg/w0 : executing action 1
0315.902826209:main Q:Reg/w0 : Called action, logging to omrelp
0315.902843598:main Q:Reg/w0 : action 2 queue: Add to LL: action 'action 2'
resumed (module 'omrelp') [try http://www.rsyslog.com/e/2359 ]
0315.902861647:main Q:Reg/w0 : action 2 queue: qqueueAdd: entry added, size
now log 1, phys 2 entries
0315.902881272:main Q:Reg/w0 : action 2 queue: EnqueueMsg advised worker start
0315.902898102:main Q:Reg/w0 : END batch execution phase, entering to commit
phase
0315.902912740:main Q:Reg/w0 : actionCommitAll: action 0, state 1, nbr to
commit 2 isTransactional 1
0315.902922604:main Q:Reg/w0 : doTransaction: have commitTransaction IF, using
that, pWrkrInfo 0x12e9b60
0315.902931039:main Q:Reg/w0 : entering actionCallCommitTransaction(), state:
itx, actionNbr 0, nMsgs 2
0315.902936519:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fae880024a0, lenBuf 131, strt data 2014-09-03T10:31:55.902066+00:00 server
rsyslogd0: action 'action 2' resumed (module 'omrelp') [try
http://www.rsyslog.com/e/0
0315.902942343:main Q:Reg/w0 : lmsig_gt: onRecordWrite (130):
2014-09-03T10:31:55.902066+00:00 server rsyslogd0: action 'action 2' resumed
(module 'omrelp') [try http://www.rsyslog.com/e/0 ]
0315.902950724:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 7,
sessState 4
0315.902959759:action 2 queue:Reg/w0: sendbuf added to unacked list
0315.902964294:action 2 queue:Reg/w0: omrelp: endTransaction
0315.902974011:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fae880024a0, lenBuf 138, strt data 2014-09-03T10:31:55.902267+00:00 server
rsyslogd-2359: action 'action 2' resumed (module 'omrelp') [try
http://www.rsyslog.com
0315.902979396:main Q:Reg/w0 : lmsig_gt: onRecordWrite (137):
2014-09-03T10:31:55.902267+00:00 server rsyslogd-2359: action 'action 2'
resumed (module 'omrelp') [try http://www.rsyslog.com/e/2359 ]
0315.902994750:main Q:Reg/w0 : strm 0x7fae880024a0: file 7(syslog) flush,
buflen 269
0315.903014974:main Q:Reg/w0 : strmPhysWrite, stream 0x7fae880024a0, len 269
0315.903036260:action 2 queue:Reg/w0: Action 1 transitioned to state: rdy
0315.903045012:action 2 queue:Reg/w0: actionCommit, in retry loop, iRet 0
0315.903049791:main Q:Reg/w0 : strm 0x7fae880024a0: file 7 write wrote 269
bytes
0315.903062442:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0315.903069415:action 2 queue:Reg/w0: regular consumer finished, iret=0, szlog
1 sz phys 2
0315.903084897:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 1
objects and enqueued 0 objects
0315.903090298:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 1, phys 1
0315.903096147:action 2 queue:Reg/w0: action 2 queue: Del from LL: action
'action 2' resumed (module 'omrelp') [try http://www.rsyslog.com/e/2359 ]
0315.903103196:action 2 queue:Reg/w0: action 1 is transactional - executing in
commit phase
0315.903110859:action 2 queue:Reg/w0: omrelp: beginTransaction
0315.903116930:action 2 queue:Reg/w0: Action 1 transitioned to state: itx
0315.903121880:action 2 queue:Reg/w0: action completing - hit
FINALIZEdoTransaction: action 1, currIParam 1
0315.903142271:action 2 queue:Reg/w0: omrelp: shutdownImmediate ptr now is
0x12e2f30
0315.903147525:action 2 queue:Reg/w0: entering actionCalldoAction(), state:
itx, actionNbr 1
0315.903152555:action 2 queue:Reg/w0:
gb-logger.skyscape.preview-dvla.co.uk:514/RELP
0315.903158001:action 2 queue:Reg/w0: relpSessWaitState returns 0
0315.903164557:action 2 queue:Reg/w0: frame to send: '9 syslog 141
<46>2014-09-03T10:31:55.902267+00:00 server rsyslogd-2359: action 'action 2'
resumed (module 'omrelp') [try http://www.rsyslog.com/e/2359 ]
'
0315.903173679:main Q:Reg/w0 : Action 0 transitioned to state: itx
0315.903188777:main Q:Reg/w0 : Action 0 transitioned to state: rdy
0315.903195467:action 2 queue:Reg/w0: ADD sess 0x7fae8c0023e0 unacked 8,
sessState 4
0315.903208771:action 2 queue:Reg/w0: sendbuf added to unacked list
0315.903214140:action 2 queue:Reg/w0: omrelp: endTransaction
0315.903220368:action 2 queue:Reg/w0: Action 1 transitioned to state: rdy
0315.903224191:action 2 queue:Reg/w0: actionCommit, in retry loop, iRet 0
0315.903229622:action 2 queue:Reg/w0: regular consumer finished, iret=0, szlog
0 sz phys 1
0315.903235462:action 2 queue:Reg/w0: DeleteProcessedBatch: we deleted 1
objects and enqueued 0 objects
0315.903240769:action 2 queue:Reg/w0: doDeleteBatch: delete batch from store,
new sizes: log 0, phys 0
0315.903246207:action 2 queue:Reg/w0: regular consumer finished, iret=4, szlog
0 sz phys 0
0315.903251366:action 2 queue:Reg/w0: action 2 queue:Reg/w0: worker IDLE,
waiting for work.
0315.903260663:main Q:Reg/w0 : actionCommit, in retry loop, iRet 0
0315.903271298:main Q:Reg/w0 : processBATCH: batch of 2 elements has been
processed
0315.903276642:main Q:Reg/w0 : regular consumer finished, iret=0, szlog 0 sz
phys 2
0315.903282782:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 2 objects and
enqueued 0 objects
0315.903286808:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new
sizes: log 0, phys 0
0315.903290757:main Q:Reg/w0 : regular consumer finished, iret=4, szlog 0 sz
phys 0
0315.903294379:main Q:Reg/w0 : main Q:Reg/w0: worker IDLE, waiting for work.
0318.052178881:main thread : DoDie called.
0318.052223456:main thread : exiting on signal 2
0318.052229475:main thread : Terminating input threads...
0318.052235576:main thread : request term via SIGTTIN for input thread
'imfile' 0xa06f5700
g to state 111
yydebug: state 111, reducing by rule 19 (value : STRING)
yydebug: after reduction, shifting from state 80 to state 112
yydebug: state 112, reducing by rule 18 (nv : NAME '=' value)
yydebug: after reduction, shifting from state 23 to state 46
yydebug: state 46, reducing by rule 17 (nvlst : nvlst nv)
yydebug: after reduction, shifting from state 3 to state 23
yydebug: state 23, reading 260 (ENDOBJ)
yydebug: state 23, shifting to state 47
yydebug: state 47, reducing by rule 34 (s_act : BEGIN_ACTION nvlst ENDOBJ)
yydebug: after reduction, shifting from state 1 to state 20
yydebug: state 20, reducing by rule 32 (actlst : s_act)
yydebug: after reduction, shifting from state 1 to state 21
yydebug: state 21, reading 0 (end-of-file)
yydebug: state 21, reducing by rule 23 (stmt : actlst)
yydebug: after reduction, shifting from state 1 to state 19
yydebug: state 19, reducing by rule 3 (conf : conf stmt)
yydebug: after reduction, shifting from state 0 to state 1
----- Original Message -----
From: "Rainer Gerhards" <[email protected]>
To: "rsyslog-users" <[email protected]>
Sent: Wednesday, 3 September, 2014 12:13:06 PM
Subject: Re: [rsyslog] Message loss during disconnect / reconnect ... (RELP)
This should not happen just because you shut down the server (do you mean
this by "logger"?). However, if you shut down the forwarding rsyslog
("client") while the server is down, RELP does not protect against loss in
that case.
Rainer
On Wed, Sep 3, 2014 at 12:55 PM, Gareth Bult <[email protected]> wrote:
> Hi,
>
> I seem to have an issue with message loss when sending messages between a
> client and a server.
> - this seems to be repeatable.
>
> Scenario;
>
> Client using RELP (or tcp):
> Server using RELP (or tcp):
> (configs below)
>
> Client> logger HELLO WORLD
> Server> Sees "HELLO WORLD"
>
> <stop logger on server>
>
> Client> HELLO WORLD 1
> Client> HELLO WORLD 2
> Client> HELLO WORLD 3
> Client> HELLO WORLD 4
>
> Client log sees all entries.
>
> <start logger on server>
>
> Client> HELLO WORLD # (to force a flush)
>
>
> Server sees>
>
> Server> HELLO WORLD 1
> Server> HELLO WORLD 3
> Server> HELLO WORLD 4
> Server> HELLO WORLD
>
>
> Looking at the code, it appears to work as follows;
>
> a. Queue first entry
> b. Queue second entry
> c. Remove entry from Queue
> d. Submit to transport
> e. If transport fails, go into retry loop
> f. When transport comes back up, proceed to dequeue next entry (!)
>
> Issues;
> - this always skips an entry on reconnect, seems to happen with both RELP
> and TCP
> - I've not tested this, but I'm guessing shutting down the client while in
> retry mode also loses the entry as the retry entry isn't on the queue
>
> It "looks" like a design issue ... i.e. one-in-the-chamber rather than
> queue peek .. am I misreading? or does anyone have a workaround??
> (or did I do something bad in the config?)
>
> Server config;
>
>
>
> module(load="impstats")
> module(load="imuxsock")
> module(load="imklog")
> module(load="imrelp")
>
> input(type="imrelp" port="514")
>
> action(type="omfile" File="/var/log/syslog" sig.provider="gt"
> sig.keepTreeHashes="on" sig.keepRecordHashes="on")
>
>
>
>
> Client config;
>
>
>
>
> module(load="imfile")
> module(load="imuxsock")
> module(load="imklog")
> module(load="omrelp")
>
> $ActionForwardDefaultTemplate RSYSLOG_ForwardFormat
>
>
>
>
> type="omrelp"
>
> Target="<target server IP>"
> Port="514"
> queue.filename="forwarding"
> queue.type="LinkedList"
> queue.saveonshutdown="on"
> queue.maxdiskspace="1g"
> queue.spoolDirectory="/var/lib/rsyslog"
> queue.size="16384"
> queue.highwatermark="12000"
> action.resumeRetryCount="10"
> action.resumeInterval="5"
>
> )
>
>
> tia
>
> Regards,
> Gareth.
>
>
> _______________________________________________
> 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.
_______________________________________________
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.
