search

etingof / snmpfwd

SNMP Proxy Forwarder
http://snmplabs.com/snmpfwd/
BSD 2-Clause "Simplified" License
67 stars 18 forks source link

Issues configuring client peer to IPv6 address #32

Closed shribigb closed 5 years ago

shribigb commented 5 years ago

First of all thanks @etingof for this, it is really useful in my use case. I am using it to forward traps from my monitoring servers to multiple destinations. I configured client and server to use ipv4 address an it works seamlessly. The issues occur when I am configuring client peers with IPv6 address. I am getting following error 

handle_write: transportAddress ('2001:4888:a02:1f24:a0:ff2:0:216', 0) -> ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0) outgoingMessage (66 octets)
00000: 30 40 02 01 01 04 06 70 75 62 6C 69 63 A7 33 02
00016: 04 3D 8D 61 FF 02 01 00 02 01 00 30 25 30 0E 06
00032: 08 2B 06 01 02 01 01 03 00 43 02 30 39 30 13 06
00048: 0A 2B 06 01 06 03 01 01 04 01 00 06 05 2B 06 01
00064: 02 05
2019-01-09T19:19:58.53 snmpfwd-client: ERROR poll error: Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 142, in handle_write
    self.socket, outgoingMessage, transportAddress
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/sockmsg.py", line 104, in sendto
    return s.sendmsg([_data], ancdata, 0, _to)
;OSError: [Errno 22] Invalid argument
;
During handling of the above exception, another exception occurred:

;Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dispatch.py", line 46, in runDispatcher
    use_poll=True, map=self.__sockMap, count=1)
;  File "/usr/local/lib/python3.4/asyncore.py", line 212, in loop
    poll_fun(timeout, map)
;  File "/usr/local/lib/python3.4/asyncore.py", line 193, in poll2
    readwrite(obj, flags)
;  File "/usr/local/lib/python3.4/asyncore.py", line 123, in readwrite
    obj.handle_error()
;  File "/usr/local/lib/python3.4/asyncore.py", line 110, in readwrite
    obj.handle_write_event()
;  File "/usr/local/lib/python3.4/asyncore.py", line 461, in handle_write_event
    self.handle_write()
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 148, in handle_write
    raise error.CarrierError('sendto() failed for %s: %s' % (transportAddress, sys.exc_info()[1]))
;pysnmp.carrier.error.CarrierError: sendto() failed for ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0): [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument
caused by <class 'pysnmp.carrier.error.CarrierError'>: sendto() failed for ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0): [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument

But I am able to send udp data from proxy to the destination using ncat.

[root@njbbsev1lb02 snmpfwd]# echo "hello" | ncat -uv6 2001:4888:a02:1f24:a0:ff2:0:212 1064
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Connected to 2001:4888:a02:1f24:a0:ff2:0:212:1064.
Ncat: 6 bytes sent, 0 bytes received in 0.01 seconds.
[root@njbbsev1lb01 ~]# ncat -uvl 1064
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Listening on :::1064
Ncat: Listening on 0.0.0.0:1064
Ncat: Connection from 2001:4888:a02:1f24:a0:ff2:0:213.
hello

My client configuration is as follows: 

config-version: 2
program-name: snmpfwd-client

peers-group {
  snmp-engine-id: 0x0102030405070809

  snmp-transport-domain: 1.3.6.1.2.1.100.1.2
  snmp-transport-options: transparent-proxy
  snmp-bind-address: ${server-snmp-peer-address}

  # time out SNMP request in 1 second
  snmp-peer-timeout: 100
  snmp-peer-retries: 0

  snmp-community-name: public
  snmp-security-name: public
  snmp-security-model: 2
  snmp-security-level: 1

  agent-1 {
    snmp-peer-address: [2001:4888:a02:1f24:a0:ff2:0:212]:1063
    snmp-peer-id: snmplabs-agent-1
  }

  agent-2 {
    snmp-peer-address: [2001:4888:a02:1f24:a0:ff2:0:212]:1064
    snmp-peer-id: snmplabs-agent-2
  }
}

trunking-group {
  trunk-bind-address: [::1]:1065
  trunk-ping-period: 60
  trunk-connection-mode: server

  trunk-id: <discover>
}

original-snmp-peer-info-group {
  orig-snmp-bind-address-pattern: .*?
  orig-snmp-context-name-pattern: .*?

  orig-snmp-pdu-type-pattern: TRAPv2
  orig-snmp-oid-prefix-pattern: .*?

  orig-snmp-engine-id-pattern: .*?
  orig-snmp-context-engine-id-pattern: .*?

  orig-snmp-transport-domain-pattern: .*?
  orig-snmp-peer-address-pattern: .*?

  orig-snmp-security-level-pattern: .*?

  orig-snmp-security-name-pattern: .*?
  orig-snmp-security-model-pattern: .*?

  orig-snmp-peer-id: any-manager
}

server-classification-group {
  server-snmp-credentials-id-pattern: .*?
  server-snmp-context-id-pattern: .*?
  server-snmp-content-id-pattern: .*?
  server-snmp-peer-id-pattern: .*?

  server-classification-id: any-classification
}

routing-map {
  matching-trunk-id-list: trunk-1
  matching-orig-snmp-peer-id-list: any-manager
  using-snmp-peer-id-list: snmplabs-agent-1 snmplabs-agent-2
  matching-server-classification-id-list: any-classification
}

Thanks,

Shri

shribigb commented 5 years ago

I narrowed it down to snmp-transport-options: transparent-proxy. If I don't run it as transparent proxy it works fine. Only with it, I get the above error.

etingof commented 5 years ago

Thank you for reporting this!

It seems to have something to do with IPv6 and address spoofing... Looking at the code, this is where pysnmp transport is asked to spoof. Then pysnmp does this on socket initialization, and this when preparing sendto parameters.

I suspect that something goes sideways at either (or both) places when it comes to IPv6... If you are at it at the moment, may be you could do some debugging (or just print outs) to see that the socket options and sendto arguments are proper?

Or I could probably add some relevant debugging to pysnmp and ask you to rerun snmpfwd with debugging on.

WDYT?

shribigb commented 5 years ago

Send me the relevant debugging to pysnmp and I will rerun snmpfwd and post the debug logs. BTW this is from strace

sendmsg(5, {msg_name(28)={sa_family=AF_INET6, sin6_port=htons(1063), inet_pton(AF_INET6, "2001:4888:a02:1f24:a0:ff2:0:212", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, msg_iov(1)=[{"0@\2\1\1\4\6public\2473\2\4}\320\202_\2\1\0\2\1\0000%0\16\6"..., 66}], msg_controllen=40, {cmsg_len=36, cmsg_level=SOL_IPV6, cmsg_type=, ...}, msg_flags=0}, 0) = -1 EINVAL (Invalid argument)
sendmsg(5, {msg_name(28)={sa_family=AF_INET6, sin6_port=htons(1064), inet_pton(AF_INET6, "2001:4888:a02:1f24:a0:ff2:0:212", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, msg_iov(1)=[{"0@\2\1\1\4\6public\2473\2\4}\320\202_\2\1\0\2\1\0000%0\16\6"..., 66}], msg_controllen=40, {cmsg_len=36, cmsg_level=SOL_IPV6, cmsg_type=, ...}, msg_flags=0}, 0) = -1 EINVAL (Invalid argument)

And this is when I run it without the transparent option

sendmsg(5, {msg_name(28)={sa_family=AF_INET6, sin6_port=htons(1063), inet_pton(AF_INET6, "2001:4888:a02:1f24:a0:ff2:0:212", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, msg_iov(1)=[{"0@\2\1\1\4\6public\2473\2\4\6\325BW\2\1\0\2\1\0000%0\16\6"..., 66}], msg_controllen=40, {cmsg_len=36, cmsg_level=SOL_IPV6, cmsg_type=, ...}, msg_flags=0}, 0) = 66
sendmsg(5, {msg_name(28)={sa_family=AF_INET6, sin6_port=htons(1064), inet_pton(AF_INET6, "2001:4888:a02:1f24:a0:ff2:0:212", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, msg_iov(1)=[{"0@\2\1\1\4\6public\2473\2\4\6\325BW\2\1\0\2\1\0000%0\16\6"..., 66}], msg_controllen=40, {cmsg_len=36, cmsg_level=SOL_IPV6, cmsg_type=, ...}, msg_flags=0}, 0) = 66
etingof commented 5 years ago

Interesting, I do not see any difference in the strace snippets you've pasted...

You may want to try the tip of this branch. The last two commits add some more io debugging and turn off the IPV6_V6ONLY socket option.

shribigb commented 5 years ago

Now I am getting following in both client and server:

2019-01-10T22:56:11.62 snmpfwd-server: INFO new engine-id 0x0102030405070809
2019-01-10T22:56:11.62 snmpfwd-server: ERROR Traceback (most recent call last):;
2019-01-10T22:56:11.62 snmpfwd-server: ERROR   File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 81, in enablePktInfo;    self.socket.setsockopt(socket.SOL_IPV6, socket.IPV6_V6ONLY, not flag);
2019-01-10T22:56:11.62 snmpfwd-server: ERROR OSError: [Errno 22] Invalid argument;
2019-01-10T22:56:11.62 snmpfwd-server: ERROR ;During handling of the above exception, another exception occurred:;;
2019-01-10T22:56:11.62 snmpfwd-server: ERROR Traceback (most recent call last):;
2019-01-10T22:56:11.62 snmpfwd-server: ERROR   File "/usr/local/bin/snmpfwd-server.py", line 981, in <module>;    main();
2019-01-10T22:56:11.62 snmpfwd-server: ERROR   File "/usr/local/bin/snmpfwd-server.py", line 710, in main;    t.enablePktInfo();
2019-01-10T22:56:11.62 snmpfwd-server: ERROR   File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 84, in enablePktInfo;    raise error.CarrierError('setsockopt() for %s failed: %s' % (self.socket.family == socket.AF_INET6 and "IPV6_RECVPKTINFO" or "IP_PKTINFO", sys.exc_info()[1]));
2019-01-10T22:56:11.62 snmpfwd-server: ERROR pysnmp.carrier.error.CarrierError: setsockopt() for IPV6_RECVPKTINFO failed: [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument;
2019-01-10T22:56:11.62 snmpfwd-server: INFO process terminated

I commented that line and checked /proc/sys/net/ipv6/bindv6only which is set to 0 on my machine. After rerunning I get following

2019-01-10T23:06:25.22 snmpfwd-server: ERROR poll error: Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dispatch.py", line 46, in runDispatcher
    use_poll=True, map=self.__sockMap, count=1)
;  File "/usr/local/lib/python3.4/asyncore.py", line 212, in loop
    poll_fun(timeout, map)
;  File "/usr/local/lib/python3.4/asyncore.py", line 193, in poll2
    readwrite(obj, flags)
;  File "/usr/local/lib/python3.4/asyncore.py", line 123, in readwrite
    obj.handle_error()
;  File "/usr/local/lib/python3.4/asyncore.py", line 108, in readwrite
    obj.handle_read_event()
;  File "/usr/local/lib/python3.4/asyncore.py", line 442, in handle_read_event
    self.handle_read()
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 163, in handle_read
    incomingMessage, transportAddress = self._recvfrom(self.socket, 65535)
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/sockmsg.py", line 95, in recvfrom
    'iov blob %s' % (len(data), _from, _to, debug.hexdump(ancdata)))
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/debug.py", line 126, in hexdump
    ['%s%.2X' % (n % 16 == 0 and ('\n%.5d: ' % n) or '', x) for n, x in zip(range(len(octets)), octs2ints(octets))])
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/debug.py", line 126, in <listcomp>
    ['%s%.2X' % (n % 16 == 0 and ('\n%.5d: ' % n) or '', x) for n, x in zip(range(len(octets)), octs2ints(octets))])
;TypeError: %X format: a number is required, not tuple
caused by <class 'TypeError'>: %X format: a number is required, not tuple
etingof commented 5 years ago

Ah, my bad! Please, try the new tip.

shribigb commented 5 years ago

New error.

2019-01-11T17:06:01.45 snmpfwd-client: ERROR Traceback (most recent call last):;
2019-01-11T17:06:01.45 snmpfwd-client: ERROR   File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 81, in enablePktInfo;    self.socket.setsockopt(socket.SOL_IPV6, socket.IPV6_V6ONLY, int(not flag));
2019-01-11T17:06:01.45 snmpfwd-client: ERROR OSError: [Errno 22] Invalid argument;
2019-01-11T17:06:01.45 snmpfwd-client: ERROR ;During handling of the above exception, another exception occurred:;;
2019-01-11T17:06:01.45 snmpfwd-client: ERROR Traceback (most recent call last):;
2019-01-11T17:06:01.45 snmpfwd-client: ERROR   File "/usr/local/bin/snmpfwd-client.py", line 910, in <module>;    main();
2019-01-11T17:06:01.45 snmpfwd-client: ERROR   File "/usr/local/bin/snmpfwd-client.py", line 629, in main;    t.enablePktInfo();
2019-01-11T17:06:01.45 snmpfwd-client: ERROR   File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 84, in enablePktInfo;    raise error.CarrierError('setsockopt() for %s failed: %s' % (self.socket.family == socket.AF_INET6 and "IPV6_RECVPKTINFO" or "IP_PKTINFO", sys.exc_info()[1]));
2019-01-11T17:06:01.45 snmpfwd-client: ERROR pysnmp.carrier.error.CarrierError: setsockopt() for IPV6_RECVPKTINFO failed: [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument;
2019-01-11T17:06:01.45 snmpfwd-client: INFO process terminated
shribigb commented 5 years ago

Also, after commenting out that line.. 

handle_write: transportAddress ('2001:4888:a02:1f24:a0:ff2:0:216', 0) -> ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0) outgoingMessage (66 octets)
00000: 30 40 02 01 01 04 06 70 75 62 6C 69 63 A7 33 02
00016: 04 53 73 7F A2 02 01 00 02 01 00 30 25 30 0E 06
00032: 08 2B 06 01 02 01 01 03 00 43 02 30 39 30 13 06
00048: 0A 2B 06 01 06 03 01 01 04 01 00 06 05 2B 06 01
00064: 02 05
2019-01-11T17:15:20.99 snmpfwd-client: ERROR poll error: Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dispatch.py", line 46, in runDispatcher
    use_poll=True, map=self.__sockMap, count=1)
;  File "/usr/local/lib/python3.4/asyncore.py", line 212, in loop
    poll_fun(timeout, map)
;  File "/usr/local/lib/python3.4/asyncore.py", line 193, in poll2
    readwrite(obj, flags)
;  File "/usr/local/lib/python3.4/asyncore.py", line 123, in readwrite
    obj.handle_error()
;  File "/usr/local/lib/python3.4/asyncore.py", line 110, in readwrite
    obj.handle_write_event()
;  File "/usr/local/lib/python3.4/asyncore.py", line 461, in handle_write_event
    self.handle_write()
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 151, in handle_write
    self.socket, outgoingMessage, transportAddress
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/sockmsg.py", line 124, in sendto
    'iov blob %r' % (len(data), _to, ancdata))
;NameError: name 'data' is not defined
caused by <class 'NameError'>: name 'data' is not defined

I replaced data with ancdata and got following:

2019-01-11T17:17:10.84 snmpfwd-client: DEBUG received trunk message #2, forwarded as SNMP message callflow-id=7592b396a7 trunk-id=trunk-1 server-snmp-engine-id=0x0102030405070809 server-snmp-transport-domain=1.3.6.1.2.1.100.1.2 server-snmp-peer-address=2001:4888:a02:1f24:a0:ff2:0:216 server-snmp-peer-port=59461 server-snmp-bind-address=2001:4888:a02:1f24:a0:ff2:0:213 server-snmp-bind-port=1061 server-snmp-security-model=2 server-snmp-security-level=1 server-snmp-security-name=public server-snmp-context-engine-id=0x0102030405070809 server-snmp-context-name=<nil> server-snmp-pdu=SNMPv2TrapPDU#1.3.6.1.2.1.1.3.0:'12345',1.3.6.1.6.3.1.1.4.1.0:'1.3.6.1.2.5', server-snmp-entity-id=any-manager server-snmp-credentials-id=snmp-credentials server-snmp-context-id=any-context server-snmp-content-id=trap-content server-snmp-peer-id=100 server-classification-id=any-classification snmp-peer-id=snmplabs-agent-2 snmp-bind-address=2001:4888:a02:1f24:a0:ff2:0:216 snmp-bind-port=0 snmp-peer-address=2001:4888:a02:1f24:a0:ff2:0:212 snmp-peer-port=1064 snmp-context-engine-id=<nil> snmp-context-name=<nil>
handle_write: transportAddress ('2001:4888:a02:1f24:a0:ff2:0:216', 0) -> ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0) outgoingMessage (66 octets)
00000: 30 40 02 01 01 04 06 70 75 62 6C 69 63 A7 33 02
00016: 04 46 FE 62 70 02 01 00 02 01 00 30 25 30 0E 06
00032: 08 2B 06 01 02 01 01 03 00 43 02 30 39 30 13 06
00048: 0A 2B 06 01 06 03 01 01 04 01 00 06 05 2B 06 01
00064: 02 05
sendto: sending 1 octets to ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0); iov blob [(41, 50, b' \x01H\x88\n\x02\x1f$\x00\xa0\x0f\xf2\x00\x00\x02\x16\x00\x00\x00\x00')]
2019-01-11T17:17:10.84 snmpfwd-client: ERROR poll error: Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 151, in handle_write
    self.socket, outgoingMessage, transportAddress
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/sockmsg.py", line 126, in sendto
    return s.sendmsg([_data], ancdata, 0, _to)
;OSError: [Errno 22] Invalid argument
;
During handling of the above exception, another exception occurred:

;Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dispatch.py", line 46, in runDispatcher
    use_poll=True, map=self.__sockMap, count=1)
;  File "/usr/local/lib/python3.4/asyncore.py", line 212, in loop
    poll_fun(timeout, map)
;  File "/usr/local/lib/python3.4/asyncore.py", line 193, in poll2
    readwrite(obj, flags)
;  File "/usr/local/lib/python3.4/asyncore.py", line 123, in readwrite
    obj.handle_error()
;  File "/usr/local/lib/python3.4/asyncore.py", line 110, in readwrite
    obj.handle_write_event()
;  File "/usr/local/lib/python3.4/asyncore.py", line 461, in handle_write_event
    self.handle_write()
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 157, in handle_write
    raise error.CarrierError('sendto() failed for %s: %s' % (transportAddress, sys.exc_info()[1]))
;pysnmp.carrier.error.CarrierError: sendto() failed for ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0): [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument

Repacing data with _data produced following:

handle_write: transportAddress ('2001:4888:a02:1f24:a0:ff2:0:216', 0) -> ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0) outgoingMessage (66 octets)
00000: 30 40 02 01 01 04 06 70 75 62 6C 69 63 A7 33 02
00016: 04 3A E4 A8 AB 02 01 00 02 01 00 30 25 30 0E 06
00032: 08 2B 06 01 02 01 01 03 00 43 02 30 39 30 13 06
00048: 0A 2B 06 01 06 03 01 01 04 01 00 06 05 2B 06 01
00064: 02 05
sendto: sending 66 octets to ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0); iov blob [(41, 50, b' \x01H\x88\n\x02\x1f$\x00\xa0\x0f\xf2\x00\x00\x02\x16\x00\x00\x00\x00')]
2019-01-11T17:20:29.29 snmpfwd-client: ERROR poll error: Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 151, in handle_write
    self.socket, outgoingMessage, transportAddress
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/sockmsg.py", line 126, in sendto
    return s.sendmsg([_data], ancdata, 0, _to)
;OSError: [Errno 22] Invalid argument
;
During handling of the above exception, another exception occurred:

;Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dispatch.py", line 46, in runDispatcher
    use_poll=True, map=self.__sockMap, count=1)
;  File "/usr/local/lib/python3.4/asyncore.py", line 212, in loop
    poll_fun(timeout, map)
;  File "/usr/local/lib/python3.4/asyncore.py", line 193, in poll2
    readwrite(obj, flags)
;  File "/usr/local/lib/python3.4/asyncore.py", line 123, in readwrite
    obj.handle_error()
;  File "/usr/local/lib/python3.4/asyncore.py", line 110, in readwrite
    obj.handle_write_event()
;  File "/usr/local/lib/python3.4/asyncore.py", line 461, in handle_write_event
    self.handle_write()
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 157, in handle_write
    raise error.CarrierError('sendto() failed for %s: %s' % (transportAddress, sys.exc_info()[1]))
;pysnmp.carrier.error.CarrierError: sendto() failed for ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0): [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument
caused by <class 'pysnmp.carrier.error.CarrierError'>: sendto() failed for ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0): [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument
etingof commented 5 years ago

Sorry for the hiccups! I've fixed this and added some more changes to the repo...

This is a pure magic how this sendmsg stuff works and what exactly it requires for proper operation...

shribigb commented 5 years ago

No worries! I am more than willing to test this..

2019-01-12T02:55:02.62 snmpfwd-client: DEBUG received SNMP response message, forwarded as trunk message #2 callflow-id=f5f657b7f9 snmp-pdu=<nil>
2019-01-12T02:55:02.62 snmpfwd-client: DEBUG received trunk message #2, forwarded as SNMP message callflow-id=f5f657b7f9 trunk-id=trunk-1 server-snmp-engine-id=0x0102030405070809 server-snmp-transport-domain=1.3.6.1.2.1.100.1.2 server-snmp-peer-address=2001:4888:a02:1f24:a0:ff2:0:214 server-snmp-peer-port=50210 server-snmp-bind-address=2001:4888:a02:1f24:a0:ff2:0:213 server-snmp-bind-port=1061 server-snmp-security-model=2 server-snmp-security-level=1 server-snmp-security-name=public server-snmp-context-engine-id=0x0102030405070809 server-snmp-context-name=<nil> server-snmp-pdu=SNMPv2TrapPDU#1.3.6.1.2.1.1.3.0:'12345',1.3.6.1.6.3.1.1.4.1.0:'1.3.6.1.2.5', server-snmp-entity-id=any-manager server-snmp-credentials-id=snmp-credentials server-snmp-context-id=any-context server-snmp-content-id=trap-content server-snmp-peer-id=100 server-classification-id=any-classification snmp-peer-id=snmplabs-agent-2 snmp-bind-address=2001:4888:a02:1f24:a0:ff2:0:214 snmp-bind-port=0 snmp-peer-address=2001:4888:a02:1f24:a0:ff2:0:212 snmp-peer-port=1064 snmp-context-engine-id=<nil> snmp-context-name=<nil>
handle_write: transportAddress ('2001:4888:a02:1f24:a0:ff2:0:214', 0) -> ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0) outgoingMessage (66 octets)
00000: 30 40 02 01 01 04 06 70 75 62 6C 69 63 A7 33 02
00016: 04 03 B4 49 78 02 01 00 02 01 00 30 25 30 0E 06
00032: 08 2B 06 01 02 01 01 03 00 43 02 30 39 30 13 06
00048: 0A 2B 06 01 06 03 01 01 04 01 00 06 05 2B 06 01
00064: 02 05
sendto: sending 66 octets to ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0); address IPv6Address('2001:4888:a02:1f24:a0:ff2:0:214'); iov blob [(41, 50, b' \x01H\x88\n\x02\x1f$\x00\xa0\x0f\xf2\x00\x00\x02\x14\x00\x00\x00\x00')]
2019-01-12T02:55:02.62 snmpfwd-client: ERROR poll error: Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 149, in handle_write
    self.socket, outgoingMessage, transportAddress
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/sockmsg.py", line 127, in sendto
    return s.sendmsg([_data], ancdata, 0, _to)
;OSError: [Errno 22] Invalid argument
;
During handling of the above exception, another exception occurred:

;Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dispatch.py", line 46, in runDispatcher
    use_poll=True, map=self.__sockMap, count=1)
;  File "/usr/local/lib/python3.4/asyncore.py", line 212, in loop
    poll_fun(timeout, map)
;  File "/usr/local/lib/python3.4/asyncore.py", line 193, in poll2
    readwrite(obj, flags)
;  File "/usr/local/lib/python3.4/asyncore.py", line 123, in readwrite
    obj.handle_error()
;  File "/usr/local/lib/python3.4/asyncore.py", line 110, in readwrite
    obj.handle_write_event()
;  File "/usr/local/lib/python3.4/asyncore.py", line 461, in handle_write_event
    self.handle_write()
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 155, in handle_write
    raise error.CarrierError('sendto() failed for %s: %s' % (transportAddress, sys.exc_info()[1]))
;pysnmp.carrier.error.CarrierError: sendto() failed for ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0): [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument
caused by <class 'pysnmp.carrier.error.CarrierError'>: sendto() failed for ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0): [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument
handle_write: transportAddress ('2001:4888:a02:1f24:a0:ff2:0:214', 0) -> ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0) outgoingMessage (66 octets)
00000: 30 40 02 01 01 04 06 70 75 62 6C 69 63 A7 33 02
00016: 04 03 B4 49 78 02 01 00 02 01 00 30 25 30 0E 06
00032: 08 2B 06 01 02 01 01 03 00 43 02 30 39 30 13 06
00048: 0A 2B 06 01 06 03 01 01 04 01 00 06 05 2B 06 01
00064: 02 05
sendto: sending 66 octets to ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0); address IPv6Address('2001:4888:a02:1f24:a0:ff2:0:214'); iov blob [(41, 50, b' \x01H\x88\n\x02\x1f$\x00\xa0\x0f\xf2\x00\x00\x02\x14\x00\x00\x00\x00')]
2019-01-12T02:55:02.62 snmpfwd-client: ERROR poll error: Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 149, in handle_write
    self.socket, outgoingMessage, transportAddress
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/sockmsg.py", line 127, in sendto
    return s.sendmsg([_data], ancdata, 0, _to)
;OSError: [Errno 22] Invalid argument
;
During handling of the above exception, another exception occurred:

;Traceback (most recent call last):
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dispatch.py", line 46, in runDispatcher
    use_poll=True, map=self.__sockMap, count=1)
;  File "/usr/local/lib/python3.4/asyncore.py", line 212, in loop
    poll_fun(timeout, map)
;  File "/usr/local/lib/python3.4/asyncore.py", line 193, in poll2
    readwrite(obj, flags)
;  File "/usr/local/lib/python3.4/asyncore.py", line 123, in readwrite
    obj.handle_error()
;  File "/usr/local/lib/python3.4/asyncore.py", line 110, in readwrite
    obj.handle_write_event()
;  File "/usr/local/lib/python3.4/asyncore.py", line 461, in handle_write_event
    self.handle_write()
;  File "/usr/local/lib/python3.4/site-packages/pysnmp/carrier/asyncore/dgram/base.py", line 155, in handle_write
    raise error.CarrierError('sendto() failed for %s: %s' % (transportAddress, sys.exc_info()[1]))
;pysnmp.carrier.error.CarrierError: sendto() failed for ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0): [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument
caused by <class 'pysnmp.carrier.error.CarrierError'>: sendto() failed for ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0): [Errno 22] Invalid argumentcaused by <class 'OSError'>: [Errno 22] Invalid argument

Its interesting to note, if I send a trap from the same host where client and servers are running, it goes through.

sendPdu: MP succeeded
sendMessage: outgoingMessage queued (66 octets)
00000: 30 40 02 01 01 04 06 70 75 62 6C 69 63 A7 33 02
00016: 04 14 AC 70 C6 02 01 00 02 01 00 30 25 30 0E 06
00032: 08 2B 06 01 02 01 01 03 00 43 02 30 39 30 13 06
00048: 0A 2B 06 01 06 03 01 01 04 01 00 06 05 2B 06 01
00064: 02 05
sendPdu: message sent
2019-01-12T02:59:02.86 snmpfwd-client: DEBUG received SNMP response message, forwarded as trunk message #7 callflow-id=4df12e9c58 snmp-pdu=<nil>
2019-01-12T02:59:02.86 snmpfwd-client: DEBUG received trunk message #7, forwarded as SNMP message callflow-id=4df12e9c58 trunk-id=trunk-1 server-snmp-engine-id=0x0102030405070809 server-snmp-transport-domain=1.3.6.1.2.1.100.1.2 server-snmp-peer-address=2001:4888:a02:1f24:a0:ff2:0:213 server-snmp-peer-port=34155 server-snmp-bind-address=2001:4888:a02:1f24:a0:ff2:0:213 server-snmp-bind-port=1061 server-snmp-security-model=2 server-snmp-security-level=1 server-snmp-security-name=public server-snmp-context-engine-id=0x0102030405070809 server-snmp-context-name=<nil> server-snmp-pdu=SNMPv2TrapPDU#1.3.6.1.2.1.1.3.0:'12345',1.3.6.1.6.3.1.1.4.1.0:'1.3.6.1.2.5', server-snmp-entity-id=any-manager server-snmp-credentials-id=snmp-credentials server-snmp-context-id=any-context server-snmp-content-id=trap-content server-snmp-peer-id=100 server-classification-id=any-classification snmp-peer-id=snmplabs-agent-2 snmp-bind-address=2001:4888:a02:1f24:a0:ff2:0:213 snmp-bind-port=0 snmp-peer-address=2001:4888:a02:1f24:a0:ff2:0:212 snmp-peer-port=1064 snmp-context-engine-id=<nil> snmp-context-name=<nil>
handle_write: transportAddress ('2001:4888:a02:1f24:a0:ff2:0:213', 0) -> ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0) outgoingMessage (66 octets)
00000: 30 40 02 01 01 04 06 70 75 62 6C 69 63 A7 33 02
00016: 04 14 AC 70 C6 02 01 00 02 01 00 30 25 30 0E 06
00032: 08 2B 06 01 02 01 01 03 00 43 02 30 39 30 13 06
00048: 0A 2B 06 01 06 03 01 01 04 01 00 06 05 2B 06 01
00064: 02 05
sendto: sending 66 octets to ('2001:4888:a02:1f24:a0:ff2:0:212', 1063, 0, 0); address IPv6Address('2001:4888:a02:1f24:a0:ff2:0:213'); iov blob [(41, 50, b' \x01H\x88\n\x02\x1f$\x00\xa0\x0f\xf2\x00\x00\x02\x13\x00\x00\x00\x00')]
handle_write: transportAddress ('2001:4888:a02:1f24:a0:ff2:0:213', 0) -> ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0) outgoingMessage (66 octets)
00000: 30 40 02 01 01 04 06 70 75 62 6C 69 63 A7 33 02
00016: 04 14 AC 70 C6 02 01 00 02 01 00 30 25 30 0E 06
00032: 08 2B 06 01 02 01 01 03 00 43 02 30 39 30 13 06
00048: 0A 2B 06 01 06 03 01 01 04 01 00 06 05 2B 06 01
00064: 02 05
sendto: sending 66 octets to ('2001:4888:a02:1f24:a0:ff2:0:212', 1064, 0, 0); address IPv6Address('2001:4888:a02:1f24:a0:ff2:0:213'); iov blob [(41, 50, b' \x01H\x88\n\x02\x1f$\x00\xa0\x0f\xf2\x00\x00\x02\x13\x00\x00\x00\x00')]

At receiver I see

 # tcpdump udp port 1064                                    tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 65535 bytes
02:57:18.799532 IP6 2001:4888:a02:1f24:a0:ff2:0:213.55687 > njbbsev1lb01.jstel: UDP, length 66

After carefully comparing these two ancdata, I see different flags are set. Following works

\x01H\x88\n\x02\x1f$\x00\xa0\x0f\xf2\x00\x00\x02\x13\x00\x00\x00\x00

This doesn't

\x01H\x88\n\x02\x1f$\x00\xa0\x0f\xf2\x00\x00\x02\x14\x00\x00\x00\x00

This makes me wonder, do I need to make any changes at sysctl level..

etingof commented 5 years ago

After carefully comparing these two ancdata, I see different flags are set.

Well, these blobs are actually IPv6 address followed by one 32bit integer. The address is quite recognizable in its hex form. Perhaps in the first case it is 2001:4888:a02:1f24:a0:ff2:0:213, while in the second it is 2001:4888:a02:1f24:a0:ff2:0:214.

This makes me wonder, do I need to make any changes at sysctl level..

That occurred to be as well... Is it that the system does not allow to spoof i.e. send packets from 2001:4888:a02:1f24:a0:ff2:0:214 while sending from 2001:4888:a02:1f24:a0:ff2:0:213 works fine? I mean is 2001:4888:a02:1f24:a0:ff2:0:213 local to your system?

In the code the IP_TRANSPARENT flag is raised...

etingof commented 5 years ago

Just another idea to check out: if you run the whole script under strace to see if that socket performs bind() on startup?

I've come across a SO post where someone resolved similar issue (on a BSD system though) by making sure the socket is bound to ANY...

shribigb commented 5 years ago

Thanks for that suggestion: Following is the strace output for socket creation and bind:

socket(PF_INET6, SOCK_DGRAM|SOCK_CLOEXEC, IPPROTO_IP) = 5
getsockopt(5, SOL_SOCKET, SO_RCVBUF, [212992], [4]) = 0
getsockopt(5, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0
setsockopt(5, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
ioctl(5, FIONBIO, [1])                  = 0
bind(5, {sa_family=AF_INET6, sin6_port=htons(0), inet_pton(AF_INET6, "::", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0
setsockopt(5, SOL_IPV6, 0x31 /* IPV6_??? */, [1], 4) = 0
setsockopt(5, SOL_IPV6, IPV6_MULTICAST_LOOP, [1], 4) = 0

Also, the system does allow spoofing for IPv4 addresses as it works seamlessly.

etingof commented 5 years ago

Hmmm, those IPV6_ options look suspicious... I'd expect them to be resolved into:

setsockopt(5, SOL_IPV6, IPV6_RECVPKTINFO, [1], 4) setsockopt(5, SOL_IPV6, IP_TRANSPARENT, [1], 4)

It turns out that sometimes these constants do not get exposed properly into Python. In such cases the hardcoded values would be used instead. May be they are different on your system?

Could you please grep you /usr/include/linux/in.h and /usr/include/linux/in6.h for the actual constants and if they differ try them in the sock fix.py linked above...?

shribigb commented 5 years ago 
[root@njbbsev1lb02 ~]# grep TRANSPARENT /usr/include/linux/in*
/usr/include/linux/in6.h:#define IPV6_TRANSPARENT        75
/usr/include/linux/in.h:#define IP_TRANSPARENT  19
[root@njbbsev1lb02 ~]# grep PKTINFO /usr/include/linux/in*
/usr/include/linux/in6.h:#define IPV6_2292PKTINFO       2
/usr/include/linux/in6.h:#define IPV6_RECVPKTINFO       49
/usr/include/linux/in6.h:#define IPV6_PKTINFO           50
/usr/include/linux/in.h:#define IP_PKTINFO      8
shribigb commented 5 years ago

It worked! I manually added IPV6_TRANSPARENT symbol in sockfix and changed following in pysnmp/carrier/asyncore/dgram/base.py

 if self.socket.family == socket.AF_INET6:
                self.socket.setsockopt(
                    socket.SOL_IPV6, socket.IPV6_TRANSPARENT, flag
                )
etingof commented 5 years ago

Awesome! I've pushed similar fix into release candidate.