search

sipcapture / paStash

pastaʃ'ʃ = Spaghetti I/O Event Data Processing, Interpolation, Correlation and beyond :spaghetti:
http://sipcapture.io
Apache License 2.0
102 stars 28 forks source link

Syslog via TCP not synonymous to syslog via UDP #51

Open systemcrash opened 5 years ago

systemcrash commented 5 years ago

When I try to use TCP (not TLS yet) to deliver syslog to a paStash node, it just barfs all over the place, and cannot re-assemble things very well at all.

When I switch over to UDP - everything plays nicely, regexp also. So all things being equal, TCP doesn't play nicely at the receiving end. I enable stdout and just see a mish-mash of bad re-assembly.

It boils down to the multi-line filter.

If we want to try to blame my device for doing something wrong on TCP, we would be pointing the finger at Rsyslogd, which the device uses. So we're up against a few decades of battle-tested code, which, as I see the packets and data upon closer inspection, look fully compliant.

I'm also a bit surprised to see things like trim() this and this in both UDP and TCP (which, to me, is either a bug or bad assumptions, but this is an aside). This now needs to be worked around in every 'app'. Especially since syslog rows can contain indented space:

0000  3c 33 30 3e 4a 75 6c 20  31 38 20 31 37 3a 33 30   <30>Jul  18 17:30
0010  3a 31 31 20 6e 65 74 6c  6f 67 67 65 72 3a 20 20   :11 netl ogger:  
0020  20 20 20 20 20 20 20 20  20 20 20 20 0a                         .

Here is a slice of where I follow a UDP stream in Wireshark containing the above:

<30>Jul 18 17:30:11 netlogger: Debug: sipfw: StartRegistration: InitiateStandaloneRequest
<30>Jul 18 17:30:11 netlogger: Debug: sipfw: Connection 1 (0x5589cdfbbdb0) reused
<30>Jul 18 17:30:11 netlogger: Debug: sipfw: NEW_TRANSACTION CLIENT 128697980 REGISTER 0x5589cdff4030
<30>Jul 18 17:30:11 netlogger: Info: sipfw: send sf (0x5589cdff4030) to 127.0.0.1:5060 via 127.0.0.1:5060 UDP connection 1:
<30>Jul 18 17:30:11 netlogger:              
<30>Jul 18 17:30:11 netlogger:              REGISTER sip:redacted.com SIP/2.0
<30>Jul 18 17:30:11 netlogger:              Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bK0f4d5546961c521e97ebd21da0b5390a
<30>Jul 18 17:30:11 netlogger:              Max-Forwards: 70

Here's my recipe. Ignore the commented out variants - I've been trying different things to no avail. 

input {
  udp {
    host => 0.0.0.0
    port => 514
    type => syslog
    }
#  tcp {
#    host => 0.0.0.0
#    port => 514
#    type => syslog_tcp
#    unserializer => raw
#    }

}

filter {
  #recipe for syslog to SIP packet re-assembly
  if [type] == syslog {
    regex {
      regex => /^<(\S+)>(\S+\s+\S+\s+\d+:\d+:\d+)(\s\S+[^:]){1,3}(:.*|:)$/
      fields =>   "syslog_priority,timestamp,syslog_program,message"
      date_format => "MMM DD HH:mm:ss Z"
    }
    syslog_pri {}
   }
  if [type] == syslog_tcp {
     multiline {
        start_line_regex => /\n/
       }
    regex {
#      regex => /<(\S+)>(\S+\s+\S+\s+\d+:\d+:\d+)(\s\S+[^:]){1,2}(:.*|:)\n/
      regex => /^(.*)$/
#      fields =>   "syslog_priority,timestamp,syslog_program,message"
      regex_flags => m
    }
    syslog_pri {}
  }

    multiline {
     start_line_regex => /^.*sipfw:\s+(send|recv).*via.*connection\s\d+:/
     max_delay => 10
     regex_flags => i
    }

    #app to parse Syslog -> SIP
    app_secret {}
#  }
}
output {
# uncomment to observe your results
# stdout {}
 hep {
    host => heplify-server
    port => 9060
    hep_id => 2001
    hep_type => 100
 }
}

Tell me what you need and I'll do my best to provide it.

I'm basically at commit 4917bd73ad013fc80526af5494e05a6649e985cf

What gives?

systemcrash commented 5 years ago

For the trim() problem: My suggestion would be to introduce a flag which can be invoked for the input modules, allowing you to sunset this trim code for those who already built code around its existence, or disable it to make new code work better.

lmangani commented 5 years ago

Hi Paul @systemcrash and thank you so much for the detailed report - this most definitely sounds odd and wrong - Let me try reproduce this and provide some feedback.

systemcrash commented 5 years ago

Another thing I've noticed: if paStash has a receiving module active for TCP, shutting down the docker image, or CTRL+C from the console takes a lot longer. I think it's trying to cleanly close the TCP connection, but in any case it seems like the OS is waiting on the TCP, and not the TCP listening to the OS...

lmangani commented 5 years ago

paStash is standing on the shoulders of giants here, it does not handle or implement its own TCP stack or workers so I'm not sure this is induced or inherited ;) Jokes aside, I'll see if there are possible modules replacement to improve those aspects once we figure out what's really happening.

systemcrash commented 5 years ago

I turned on simple (debug) logging to show what my AppSecret ingests from the syslog_tcp module. You can see how it even preserves the indented space and doesn't even trim() it. Right from the start, it (multiline and regexp) seems to have difficulty coping.

Here is the corresponding recipe:

input {
  tcp {
    host => 0.0.0.0
    port => 514
    type => syslog_tcp
    unserializer => raw
    }
}

filter {
  if [type] == syslog_tcp {
    regex {
      regex => /^(.*)$/
      regex_flags => m
    }
    syslog_pri {}
  }

    multiline {
     start_line_regex => /^.*sipfw:\s+(send|recv).*via.*connection\s\d+:/
     max_delay => 10
     regex_flags => i
    }

    #app to parse Syslog -> SIP
    app_secret {}
}

output {
 stdout {}
}

This is logged for what comes in via TCP - note Function ingested data is all one block, not separate blocks:

[Thu, 05 Sep 2019 18:01:27 GMT] NOTICE Starting pastash 1.0.46
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Max http socket 100
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Loading config files from : /config
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Files loaded from directory, 9 urls found
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Loading config : 12 urls
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing output Stdout
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing filter AddHost
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing filter AddTimestamp
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing filter AddVersion
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing filter Regex
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing regex filter, regex : /^(.*)$/m, fields , flags: m
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing filter SyslogPri
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing filter Multiline
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initialized multiline filter with start_line_regex: /^.*sipfw:\s+(send|recv).*via.*connection\s\d+:/i, flags: i
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing filter AppSecret
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initialized AppSecret Syslog to SIP/HEP parser
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Initializing input Tcp
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Start listening on tcp 0.0.0.0:514
[Thu, 05 Sep 2019 18:01:27 GMT] INFO Config loaded.
> Function ingested data: {
  message: '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: StartRegistration: InitiateStandaloneRequest\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: Connection 1 (0x55eafa8bdac0) reused\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: NEW_TRANSACTION CLIENT 125713783 REGISTER 0x55eafa896180\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Info: sipfw: send sf (0x55eafa896180) to 127.0.0.1:5060 via 127.0.0.1:5060 UDP connection 1:\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              \n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              REGISTER sip:redacted.com SIP/2.0\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bKdf148750b9b99c6c46307d1ae0639d4a\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              To: <sip:2065085852@redacted.com>\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              From: <sip:2065085852@redacted.com>;tag=527ffa36\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Call-ID: 424f2511-14796da-6fccdc9@sipgt-1b0ff605\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              CSeq: 125713783 REGISTER\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Max-Forwards: 70\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              User-Agent: redacted-UA\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Supported: path\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Contact: <sip:2065085852@127.0.0.1>;expires=3600\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Content-Length: 0\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: Recv 473 bytes from 127.0.0.1, connection 1\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Info: sipfw: recv from 127.0.0.1:5060 via 127.0.0.1:5060 UDP connection 1:\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              \n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              REGISTER sip:redacted.com SIP/2.0\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bKdf148750b9b99c6c46307d1ae0639d4a\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              To: <sip:2065085852@redacted.com>\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              From: <sip:2065085852@redacted.com>;tag=527ffa36\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Call-ID: 424f2511-14796da-6fccdc9@sipgt-1b0ff605\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              CSeq: 125713783 REGISTER\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Max-Forwards: 70\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              User-Agent: redacted-UA\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Supported: path\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Contact: <sip:2065085852@127.0.0.1>;expires=3600\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Content-Length: 0\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: Connection 1 (0x55eafa8bdac0) reused\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: NEW_TRANSACTION SERVER 125713783 REGISTER 0x55eafa8882a0\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: DP: DP disabled for method REGISTER.\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: DP: All domains not processed by DP.\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: SIP forward: sip:redacted.com\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:               -> sip:redacted.com (prio 0, condition "always")\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: Proxy forwards REGISTER request.\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Info: sipfw: Forward to outbound proxy: sip:redacted.com:6061;transport=tls , qos: 2, dscp: 0xff\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: DNS A lookup for target: redacted.com\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: Found query string (redacted.com) in A cache.\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: SIP request from grp:1:secl:10, to grp:2:secl:1.\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: IPaddr 127.0.0.1 needs modification in group 2\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: IPaddr 127.0.0.1 needs modification in group 2\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: Connection 2 (0x55eafa8c8360) reused\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Info: sipfw: send sf (0x55eafa8c8920) to 192.0.2.1:6061 via 192.0.2.2:24493 TLS connection 2:\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              \n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              REGISTER sip:redacted.com SIP/2.0\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Via: SIP/2.0/TLS 192.0.2.2:5061;branch=z9hG4bK5a2383f7fdad15e99339d4a657360a2a.0\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Via: SIP/2.0/UDP 192.0.2.2:5060;branch=z9hG4bKdf148750b9b99c6c46307d1ae0639d4a.fA1CwNGO5Mr4l3md2HAW-g__\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              To: <sip:2065085852@redacted.com>\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              From: <sip:2065085852@redacted.com>;tag=527ffa36\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Call-ID: 424f2511-14796da-6fccdc9@sipgt-1b0ff605\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              CSeq: 125713783 REGISTER\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Max-Forwards: 69\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              User-Agent: redacted-UA\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Supported: path\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Contact: <sip:bqerqTcaIGGfa1REOv6.@192.0.2.2:5061;transport=tls>;expires=90\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger:              Content-Length: 0\n' +
    '<30>Sep  5 19:59:57 Firewall netlogger: Debug: sipfw: NEW_TRANSACTION CLIENT 125713783 REGISTER 0x55eafa8c8920',
  host: '10.1.2.3',
  tcp_port: '514',
  type: 'syslog_tcp',
  '@timestamp': '2019-09-05T18:01:51.812Z',
  '@version': '1'
}

Comments: there are at least 3 separate 'start lines' for multi-line, but one large block is ingested.

systemcrash commented 5 years ago

For comparison, this is what happens via UDP (when you look at the differences, you'll see how TCP is misbehaving)

recipe

input {
  udp {
    host => 0.0.0.0
    port => 514
    type => syslog
    }
}

filter {
  #recipe for ingate (version < 6.3.0) syslog to SIP packet re-assembly
  if [type] == syslog {
    regex {
      regex => /^<(\S+)>(\S+\s+\S+\s+\d+:\d+:\d+)(\s\S+[^:]){1,3}(:.*|:)$/
      fields =>   "syslog_priority,timestamp,syslog_program,message"
      date_format => "MMM DD HH:mm:ss Z"
    }
    syslog_pri {}
   }

    multiline {
     start_line_regex => /^.*sipfw:\s+(send|recv).*via.*connection\s\d+:/
     max_delay => 10
     regex_flags => i
    }

    #app to parse Syslog -> SIP
    app_secret {}
}

output {
 stdout {}
}

log

[Thu, 05 Sep 2019 18:29:39 GMT] NOTICE Starting pastash 1.0.46
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Max http socket 100
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Loading config files from : /config
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Files loaded from directory, 8 urls found
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Loading config : 11 urls
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing output Stdout
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing filter AddHost
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing filter AddTimestamp
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing filter AddVersion
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing filter Regex
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing regex filter, regex : /^<(\S+)>(\S+\s+\S+\s+\d+:\d+:\d+)(\s\S+[^:]){1,3}(:.*|:)$/, fields syslog_priority,timestamp,syslog_program,message, date format MMM DD HH:mm:ss Z, flags:
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing filter SyslogPri
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing filter Regex
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing regex filter, regex : /^(.*)$/m, fields , flags: m
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing filter SyslogPri
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing filter Multiline
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initialized multiline filter with start_line_regex: /^.*sipfw:\s+(send|recv).*via.*connection\s\d+:/i, flags: i
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing filter AppIngate
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initialized AppIngate Syslog to SIP/HEP parser
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Initializing input Udp
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Start listening on udp 0.0.0.0:514
[Thu, 05 Sep 2019 18:29:39 GMT] INFO Config loaded.
> Function ingested data: {
  message: ': Info: sipfw: recv from 192.0.2.1:6061 via 192.0.2.2:24493 TLS connection 2:\n' +
    ':\n' +
    ':              SIP/2.0 200 OK\n' +
    ':              Via: SIP/2.0/TLS 192.0.2.2:5061;received=192.0.2.2;rport=24493;branch=z9hG4bK1038369ed4dc5b969339d4a657360a2a.0\n' +
    ':              Via: SIP/2.0/UDP 192.0.2.2:5060;branch=z9hG4bKd8d7e55068fee52cb12c746412d1ee63.jwUU3nvQc-dwAobhzutpXw__\n' +
    ':              From: <sip:2065085852@redacted.com>;tag=0da31f74\n' +
    ':              To: <sip:2065085852@redacted.com>;tag=a9mSc6af3b37781a0fa033\n' +
    ':              Call-ID: 424f2511-14796da-6fccdc9@sipgt-1b0ff605\n' +
    ':              CSeq: 125713824 REGISTER\n' +
    ':              Contact: <sip:bqerqTcaIGGfa1REOv6.@192.0.2.2:5061>;expires=0\n' +
    ':              Expires: 0\n' +
    ':              Server: Redacted\n' +
    ':              Content-Length: 0\n' +
    ': Debug: sipfw: RESPONSE200 CLIENT 125713824 REGISTER 0x55eafa8e9b40\n' +
    ': Debug: sipfw: SIP response from grp:2:secl:1, to grp:1:secl:10.\n' +
    ': Debug: sipfw: FINISHED CLIENT 125713824 REGISTER 0x55eafa8e9b40\n' +
    ': Debug: sipfw: DELETED_TRANSACTION CLIENT 125713824 REGISTER 0x55eafa8e9b40',
  host: '10.1.2.3',
  udp_port: '514',
  type: 'syslog',
  '@timestamp': '2019-09-05T20:27:57.000+0000',
  '@version': '1',
  syslog_priority: 30,
  syslog_program: ' netlogger',
  syslog_severity: 'informational',
  syslog_facility: 'daemon'
}
AppSecret Syslog to SIP/HEP parser; SIP/HEP payload assembled; Call-ID: 424f2511-14796da-6fccdc9@sipgt-1b0ff605

[STDOUT] {
  "payload": "SIP/2.0 200 OK\r\nVia: SIP/2.0/TLS 192.0.2.2:5061;received=192.0.2.2;rport=24493;branch=z9hG4bK1038369ed4dc5b969339d4a657360a2a.0\r\nVia: SIP/2.0/UDP 192.0.2.2:5060;branch=z9hG4bKd8d7e55068fee52cb12c746412d1ee63.jwUU3nvQc-dwAobhzutpXw__\r\nFrom: <sip:2065085852@redacted.com>;tag=0da31f74\r\nTo: <sip:2065085852@redacted.com>;tag=a9mSc6af3b37781a0fa033\r\nCall-ID: 424f2511-14796da-6fccdc9@sipgt-1b0ff605\r\nCSeq: 125713824 REGISTER\r\nContact: <sip:bqerqTcaIGGfa1REOv6.@192.0.2.2:5061>;expires=0\r\nExpires: 0\r\nServer: AccessLine SIP Proxy/release/vco-2018.3\r\nContent-Length: 0\r\n",
  "rcinfo": {
    "type": "HEP",
    "version": 3,
    "payload_type": 1,
    "ip_family": 2,
    "protocol": 6,
    "proto_type": 1,
    "correlation_id": "424f2511-14796da-6fccdc9@sipgt-1b0ff605",
    "srcIp": "192.0.2.1",
    "srcPort": "6061",
    "dstIp": "192.0.2.2",
    "dstPort": "24493",
    "time_sec": 1567715277,
    "time_usec": 1567715277000000
  }
}
> Function ingested data: {
  message: ': Info: sipfw: send sf (0x55eafa8de6a0) to 127.0.0.1:5060 via 127.0.0.1:5060 UDP connection 1:\n' +
    ':\n' +
    ':              SIP/2.0 200 OK\n' +
    ':              Via: SIP/2.0/UDP 127.0.0.1:5060;branch=z9hG4bKd8d7e55068fee52cb12c746412d1ee63\n' +
    ':              From: <sip:2065085852@redacted.com>;tag=0da31f74\n' +
    ':              To: <sip:2065085852@redacted.com>;tag=a9mSc6af3b37781a0fa033\n' +
    ':              Call-ID: 424f2511-14796da-6fccdc9@sipgt-1b0ff605\n' +
    ':              CSeq: 125713824 REGISTER\n' +
    ':              Contact: <sip:bqerqTcaIGGfa1REOv6.@192.0.2.2:5061>;expires=0\n' +
    ':              Expires: 0\n' +
    ':              Server: AccessLine SIP Proxy/release/vco-2018.3\n' +
    ':              Content-Length: 0\n' +
    ':              IX-Prev-Hop: 192.0.2.1\n' +
    ': Debug: sipfw: Recv 493 bytes from 127.0.0.1, connection 1',
  host: '10.1.2.3',
  udp_port: '514',
  type: 'syslog',
  '@timestamp': '2019-09-05T20:27:57.000+0000',
  '@version': '1',
  syslog_priority: 30,
  syslog_program: ' netlogger',
  syslog_severity: 'informational',
  syslog_facility: 'daemon'
}
AppSecret Syslog to SIP/HEP parser; SIP/HEP payload assembled; Call-ID: 424f2511-14796da-6fccdc9@sipgt-1b0ff605
systemcrash commented 5 years ago

So irrespective of what regexp I have in the recipe, e.g.

      regex => /^<(\S+)>(\S+\s+\S+\s+\d+:\d+:\d+)(\s\S+[^:]){1,3}(:.*|:)$/

or

      regex => /^(.*)$/

The TCP syslog received lines are passed verbatim, and are not reduced:

'<30>Sep  5 19:59:57 Firewall netlogger: ...'

Like they are via UDP:

':\n'
systemcrash commented 5 years ago

I guess you would need the multiline filter to split those? What are you actually trying to do here? Considering the size of that message, TCP seems to be working fine to deliver it.

So as stated in the original submission: it's like multiline is completely bypassed when using TCP for reception. UDP, fine. All things being equal, TCP is just... weird.

systemcrash commented 5 years ago

Any progress on your investigations?

systemcrash commented 4 years ago

If you can make any progress on this, this would promise integration of a few SBCs and PBXes.

lmangani commented 4 years ago

@systemcrash apologies for the long break - I'll get to this soon. Are you using the latest @pastash/pastash w/ plugin extensions by any chance? would be easier to fix there

systemcrash commented 4 years ago

Pulled in the latest. Using 8b894632517ec911a1fc607c490c0df936007eac How would I verify I'm using w/ plugin exstensions?

Edit: No difference in behaviour

lmangani commented 4 years ago

the global version uses @pastash/pastash and the pastash plugins at https://github.com/sipcapture/pastash_plugins

systemcrash commented 4 years ago

shrug like I said, I'm using 8b894632517ec911a1fc607c490c0df936007eac (from this repo)

I run docker-compose up - I don't use npm directly. Although I see a few of those commands fly past when building an updated image.

lmangani commented 4 years ago

Great. Mind using the branch has nothing to do with how it should be installed to work. Keep in mind, the modular version expects globally installed @pastash/plugins in order to run. Since the point is shrinking down, you might want to build your own Docker container with only the packages you want/need installed.

FROM node:10
RUN npm install --unsafe-perm -g @pastash/pastash @pastash/output_loki
COPY ./loki-pastash.conf /pastash.conf
EXPOSE 3100
CMD [ "pastash", "--config_file=/pastash.conf" ]
systemcrash commented 4 years ago

Got it - thanks. Is a pastash.conf possible in a docker-compose scenario?

If you have any test branches you want me to try, post it here. This (debug) installation will be exclusively using github/docker-compose to build.