PacketFence - BTS - PacketFence
View Issue Details
IDProjectCategoryView StatusDate SubmittedLast Update
0001052PacketFencecorepublic2010-08-26 11:122011-01-26 15:38
Reporterobilodeau 
Assigned Toobilodeau 
PriorityhighSeverityminorReproducibilityrandom
StatusclosedResolutionfixed 
PlatformOSOS Version
Product Version1.9.0 
Target Version1.9.1Fixed in Version1.9.1 
fixed in git revision
fixed in mtn revision381d8aefe12ccd91661639dee279aeeb5706e95d
Summary0001052: pf::SNMP not properly initialized or configuration parsing problem?
DescriptionThis happened to me twice this week and it's very odd.

Aug 26 11:01:22 pfsetvlan(1) INFO: secureMacAddrViolation trap received on 192.168.1.67 ifIndex 1017 
for 90:e6:ba:70:e7:4b (main::handleTrap)
Aug 26 11:01:22 pfsetvlan(1) DEBUG: opening SNMP v1 read connection to 192.168.1.74 (pf::SNMP::connectRead)

Aug 26 11:01:22 pfsetvlan(1) TRACE: SNMP get_request for sysLocation: 1.3.6.1.2.1.1.6.0 (pf::SNMP::connectRead)

Aug 26 11:01:26 pfsetvlan(1) ERROR: error creating SNMP v1 read connection to 192.168.1.74: No response 
from remote host '192.168.1.74' (pf::SNMP::connectRead)
Aug 26 11:01:26 pfsetvlan(1) TRACE: SNMP get_table for extremeVlanIfVlanId: 1.3.6.1.4.1.1916.1.2.1.2.1.10 
(pf::SNMP::Extreme::_getVlanTagLookupTable)
Aug 26 11:01:26 pfsetvlan(1) TRACE: SNMP get_table for extremeFdbMacFdbTable: 1.3.6.1.4.1.1916.1.16.1 
(pf::SNMP::Extreme::getAllSecureMacAddresses)
Aug 26 11:01:26 pfsetvlan(1) TRACE: SNMP get_table for extremeFdbMacFdbStatus: 1.3.6.1.4.1.1916.1.16.1.1.5 
(pf::SNMP::Extreme::getAllSecureMacAddresses)


In plain english:
- even though trap comes from 1.67, the first read attempts are made on 1.74 by this same thread. There's no explanation for that behavior. The first time it happened to me it was the opposite situation, a trap from 1.74 and read attempts on 1.67..

PacketFence was restarted right before the new test on both occurrence..

What's going on?
Steps To Reproduce
Additional Information
TagsNo tags attached.
Relationships
Attached Files
Issue History
Date ModifiedUsernameFieldChange
2010-08-26 11:12obilodeauNew Issue
2010-08-26 11:13obilodeauNote Added: 0001636
2010-09-10 16:11obilodeauNote Added: 0001651
2010-09-10 16:22obilodeauNote Added: 0001652
2010-09-10 16:22obilodeauPrioritynormal => high
2010-09-10 16:25obilodeauTarget Version1.9.2 => 1.9.1
2010-09-10 18:11obilodeauNote Added: 0001653
2010-09-10 18:13obilodeaumtn revision => d4c36aced3cecc4767dfd92a1d8a68b2554fa194
2010-09-10 18:13obilodeauNote Added: 0001654
2010-09-10 18:13obilodeauStatusnew => resolved
2010-09-10 18:13obilodeauFixed in Version => 1.9.1
2010-09-10 18:13obilodeauResolutionopen => fixed
2010-09-10 18:13obilodeauAssigned To => obilodeau
2010-09-10 18:27obilodeauNote Edited: 0001654
2010-09-10 18:28obilodeaumtn revisiond4c36aced3cecc4767dfd92a1d8a68b2554fa194 => 381d8aefe12ccd91661639dee279aeeb5706e95d
2011-01-26 15:38obilodeauStatusresolved => closed

Notes
(0001636)
obilodeau   
2010-08-26 11:12   
Identified as a bug in 1.9.0 but could be present well before then.
(0001651)
obilodeau   
2010-09-10 16:11   
again, another re-occurrence:

Sep 10 16:02:18 pfsetvlan(14) INFO: nb of items in queue: 1; nb of threads running: 0 (main::startTrapHandlers)

Sep 10 16:02:18 pfsetvlan(14) DEBUG: opening SNMP v1 read connection to 192.168.1.64 (pf::SNMP::connectRead)

Sep 10 16:02:18 pfsetvlan(14) TRACE: SNMP get_request for sysLocation: 1.3.6.1.2.1.1.6.0 (pf::SNMP::connectRead)

Sep 10 16:02:18 pfsetvlan(14) TRACE: SNMP get_request for ifType: 1.3.6.1.2.1.2.2.1.3.1 (pf::SNMP::getIfType)

Sep 10 16:02:18 pfsetvlan(14) DEBUG: initializing database connection (pf::SNMP::connectMySQL)
Sep 10 16:02:18 pfsetvlan(14) DEBUG: connecting to database server localhost as user root; database name 
is pf (pf::SNMP::connectMySQL)
Sep 10 16:02:18 pfsetvlan(14) INFO: secureMacAddrViolation trap received on 192.168.1.64 ifIndex 1 for 
90:e6:ba:70:e7:4b (main::handleTrap)
Sep 10 16:02:21 pfsetvlan(14) DEBUG: opening SNMP v1 read connection to 192.168.1.67 (pf::SNMP::connectRead)

Sep 10 16:02:21 pfsetvlan(14) TRACE: SNMP get_request for sysLocation: 1.3.6.1.2.1.1.6.0 (pf::SNMP::connectRead)

Sep 10 16:02:25 pfsetvlan(14) ERROR: error creating SNMP v1 read connection to 192.168.1.67: No response 
from remote host '192.168.1.67' (pf::SNMP::connectRead)


thread failed to start: 500 Can't connect to 192.168.1.67:80 (connect: No route
        to host) at /usr/local/pf/lib/pf/SNMP/Extreme.pm line 898 (0000001)
    (W threads)(S) The entry point function of threads->create() failed for some reason.


You can clearly see that it starts in the right direction but then some old remaining data causes the thread to start querying a wrong IP...
(0001652)
obilodeau   
2010-09-10 16:22   
In the above case, the thread crashed and the trap is marked as in process in the trap queue. This means that this switch/ifIndex is locked forever. We want to avoid that. Increasing priority.
(0001653)
obilodeau   
2010-09-10 18:11   
Ok, so this is two things:

1) the connection on a seemingly unrelated switch is in fact a cleanup attempt in pfsetvlan's do_port_security. It checks the security table of the old switch to remove the secure entry if it's still there. In my lab since I keep powering down the old switches I was getting errors that I didn't understood.

Fix: I added some info-level log entries to explain that it's about to talk to an old switch and to report that it failed doing so. I won't be confused by this again.

2) the thread that died. Well, it would seem that the newly introduced dependency to talk to web services enabled switches dies on you on some occasions. I wrapped it's use behind a try {} catch {}; to handle these problems. The code will be pushed when VoIP support will be complete.

So, problem description is far from accurate ;)
(0001654)
obilodeau   
2010-09-10 18:13   
(edited on: 2010-09-10 18:27)
problem 1 fixed by 381d8aefe12ccd91661639dee279aeeb5706e95d

problem 2 already fixed in lab, fix will come in mtn soon but i'm still closing the issue for now as it is unrelated to the source of the problem