PacketFence - BTS - PacketFence
View Issue Details
IDProjectCategoryView StatusDate SubmittedLast Update
0001243PacketFencecorepublic2011-08-11 02:492011-10-24 20:24
Reporterpsnizek 
Assigned Toobilodeau 
PrioritynormalSeverityminorReproducibilityalways
StatusclosedResolutionfixed 
PlatformOSOS Version
Product Version2.2.1 
Target Version3.0.0Fixed in Version3.0.0 
fixed in git revision
fixed in mtn revision
Summary0001243: duplicate entries errors in pf::os::read_dhcp_fingerprints_conf at pfcmd service ... start or pfcmd update oui|fingerprints
DescriptionHello

pfcmd is the only one to call dhcp_fingerprints_conf. On my box it produces this output in packetfence log:
pfcmd(0) WARN: database query failed with: Duplicate entry '3,1,6,15,121' for key 'PRIMARY'. (errno: 1062), will try again (pf::db::db_query_execute)

The SQL statements run at pfcmd service httpd start are
DELETE FROM os_type
DELETE FROM os_class
that are found in os::pf::os_db_prepare.
However, a DELETE FROM dhcp_fingerprint is not found anywhere although the full flat file seems to be inserted into the database every time the pfcmd service someservice start or pfcmd update oui|fingerprints commands are run. This causes here duplicate entry errors logged in packetfence.log.

Apart from that, I am not really sure about the exact function of pf::trigger qw(trigger_in_range). In particular this code fragment taken from the function seems to be always true:
# what exactly is the sense of this code?
} elsif ( $element =~ /^\d+\s*\-\s*\d+$/ ) {
    my ( $begin, $end ) = split( /\s*\-\s*/, $element );
    if ( $trigger >= $begin && $trigger <= $end ) {
    return (1);
}
Commenting the trigger_in_range function seems to do no harm as it is only used in os.pm in read_dhcp_fingerprints_conf and is imported but unused in freeradius.pm. If the fingerprints table in mysql is not completely deleted, this code also generates a lot of duplicate entry errors.

Best wishes,
Philipp
Steps To Reproduce
Additional InformationNot well tested at all but this patch reduced the errors to zero:

--- os.pm.orig 2011-07-14 13:50:17.990982129 +0200
+++ os.pm 2011-08-11 08:26:31.739588886 +0200
@@ -54,6 +54,8 @@ sub os_db_prepare {
     $os_statements->{'os_delete_all_sql'} = get_db_handle()->prepare(qq[ DELETE FROM os_type ]);

     $os_statements->{'os_class_delete_all_sql'} = get_db_handle()->prepare(qq[ DELETE FROM os_class ]);
+
+ $os_statements->{'dhcp_fingerprint_delete_all_sql'} = get_db_handle()->prepare(qq[ DELETE FROM dhcp_fingerprint ]);

     $os_statements->{'dhcp_fingerprint_add_sql'} = get_db_handle()->prepare(
         qq [ INSERT INTO dhcp_fingerprint(fingerprint,os_id) VALUES(?,?) ]);
@@ -105,6 +107,7 @@ sub read_dhcp_fingerprints_conf {
     my $fp_total;
     my %dhcp_fingerprints;

+ db_query_execute(OS, $os_statements, 'dhcp_fingerprint_delete_all_sql');
     db_query_execute(OS, $os_statements, 'os_delete_all_sql');
     db_query_execute(OS, $os_statements, 'os_class_delete_all_sql');
     tie %dhcp_fingerprints, 'Config::IniFiles',
TagsNo tags attached.
Relationships
Attached Files
Issue History
Date ModifiedUsernameFieldChange
2011-08-11 02:49psnizekNew Issue
2011-08-11 11:44obilodeauNote Added: 0002120
2011-08-11 11:44obilodeauStatusnew => acknowledged
2011-08-11 11:44obilodeauCategorydhcp => core
2011-08-11 11:44obilodeauTarget Version => +1
2011-08-11 11:44obilodeauStatusacknowledged => assigned
2011-08-11 11:44obilodeauAssigned To => obilodeau
2011-08-11 11:55obilodeauNote Added: 0002121
2011-08-11 11:57obilodeauNote Added: 0002122
2011-08-11 12:23obilodeauNote Added: 0002123
2011-08-11 12:36obilodeauNote Edited: 0002123
2011-08-11 15:29psnizekNote Added: 0002124
2011-08-11 15:44psnizekNote Added: 0002125
2011-08-11 16:04psnizekNote Added: 0002126
2011-08-12 09:44obilodeauNote Added: 0002127
2011-08-12 09:44obilodeauStatusassigned => feedback
2011-08-12 10:46psnizekNote Added: 0002128
2011-08-12 11:47obilodeauNote Added: 0002129
2011-08-12 11:47obilodeauStatusfeedback => resolved
2011-08-12 11:47obilodeauFixed in Version => trunk
2011-08-12 11:47obilodeauResolutionopen => fixed
2011-09-21 22:07obilodeauFixed in Versiontrunk => 3.0.0
2011-09-21 22:15obilodeauNote Added: 0002248
2011-09-21 22:16obilodeauStatusresolved => closed
2011-10-24 20:24obilodeauTarget Version+1 => 3.0.0

Notes
(0002120)
obilodeau   
2011-08-11 11:44   
dhcp_fingerprint
You are right about the missing delete all for dhcp_fingerprint. Although I don't understand why I'm not getting the duplicate key errors in most of our setup..

On what linux distro / version do you run packetfence?

trigger_in_range
This is to support a trigger like OS:300-310 but almost no one uses that feature. To me the code seems correct (you are missing a curly bracket in what you pasted) but I'll write a test for it and validate all the options. Also, I don't like the split /../ when a capturing regexp could've been used in the first place.
(0002121)
obilodeau   
2011-08-11 11:55   
After looking around a bit, there are constraints on the dhcp_fingerprint table:
> CONSTRAINT `0_65` FOREIGN KEY (`os_id`) REFERENCES `os_type` (`os_id`) ON DELETE CASCADE ON UPDATE CASCADE

So I would guess that it should empty the dhcp_fingerprint table when you flush the os_type table.

What do you get if you grep for 3,1,6,15,121? Like: 
# grep 3,1,6,15,121 conf/dhcp_fingerprints.conf 
3,1,6,15,121


For the record, I've been seeing errors on startup from time to time but I've never been able to reliably reproduce. I'm just unsure whether I should remove the constraints and add a delete_all or if I should try to understand more what's going on.
(0002122)
obilodeau   
2011-08-11 11:57   
Oh, maybe another thing to check is if you have the proper constraints on your database:
show create table dhcp_fingerprint
(0002123)
obilodeau   
2011-08-11 12:23   
(edited on: 2011-08-11 12:36)
Forget what I said about trigger_in_range, it's not what I first thought it was. In any case, it's doing it's job and it's not related to your issue. I made some changes to make it purpose clearer.
(0002124)
psnizek   
2011-08-11 15:29   
mysql> show create table dhcp_fingerprint\G;
*************************** 1. row ***************************
       Table: dhcp_fingerprint
Create Table: CREATE TABLE `dhcp_fingerprint` (
  `fingerprint` varchar(255) NOT NULL,
  `os_id` int(11) NOT NULL,
  PRIMARY KEY (`fingerprint`),
  KEY `os_id_key` (`os_id`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1
1 row in set (0.00 sec)

ERROR:
No query specified

The sql script used is the one that comes with the tar ball in db/pf-schema-2.2.0.sql.

I run Packetfence on a modified Slackware 13.1 box. And you are absolutely right if you say that the Perl cpan dependencies are enormous ;)

trigger_in_range
This function is only really used in os.pm. The calling function is read_dhcp_fingerprints_conf which is only called by bin/pfcmd. I introduced a line into trigger_in_range that writes to packetfence.log what is being compared.
The result is this:
Aug 11 08:27:52 pfcmd(0) INFO: trigger >= begin && trigger <= end; Element = Trigger; Trigger: 427, Begin: 400, End: 499 (pf::trigger::trigger_in_range)
Aug 11 08:27:52 pfcmd(0) INFO: trigger >= begin && trigger <= end; Element = Trigger; Trigger: 428, Begin: 400, End: 499 (pf::trigger::trigger_in_range)
Aug 11 08:27:52 pfcmd(0) INFO: trigger >= begin && trigger <= end; Element = Trigger; Trigger: 429, Begin: 400, End: 499 (pf::trigger::trigger_in_range)
Aug 11 08:27:52 pfcmd(0) INFO: trigger >= begin && trigger <= end; Element = Trigger; Trigger: 500, Begin: 500, End: 599 (pf::trigger::trigger_in_range)

As seen here, trigger >= begin && trigger <= end. This seems to be always true for every [os $number] in dhcp_fingerprints.conf.

# grep 3,1,6,15,121 conf/dhcp_fingerprints.conf
3,1,6,15,121
(0002125)
psnizek   
2011-08-11 15:44   
Just out of curiosity, I just checked the pf-schema.sql I used. There, the dhcp_fingerprint table looks like this:

CREATE TABLE dhcp_fingerprint (
  fingerprint varchar(255) NOT NULL,
  os_id int(11) NOT NULL,
  PRIMARY KEY fingerprint (fingerprint),
  KEY os_id_key (os_id),
  CONSTRAINT `0_65` FOREIGN KEY (`os_id`) REFERENCES `os_type` (`os_id`) ON DELETE CASCADE ON UPDATE CASCADE
) ENGINE=InnoDB;

It's InnoDB and not MYISAM and the constraint is there.
(0002126)
psnizek   
2011-08-11 16:04   
Problem was, that the mysql storage engine was default myisam and not innodb.
Sorry for that.
(0002127)
obilodeau   
2011-08-12 09:44   
I'm kind of unsure why you were in MyISAM and didn't have the constraint in the first place.. I want to make sure that it can't happen for someone else.

Did you started with pf 2.2.1 or did you installed a previous version then upgraded? A bug could be in the db upgrade scripts.
(0002128)
psnizek   
2011-08-12 10:46   
This is the question I was trying to answer today.

I started with pf 2.2.1. I did not touch older scripts.
(0002129)
obilodeau   
2011-08-12 11:47   
Ok, for now I will mark this as resolved and if you have an idea or more information about what could've caused this let us know!

I did move trigger_in_range into pf::os and renamed it so that its purpose is clearer.

Thanks!
(0002248)
obilodeau   
2011-09-21 22:15   
fix released in 3.0