Basic DHCPv4 function

[ryan.n....@gmail.com]

Have the server up and running (theoretically) but I can't get it to hand out an IP.  I can see the broadcast dhcp discover request arriving on the interface but the server never logs anything and no offer is provided.  Have a super simple configuration and setup in place with two vm's sharing an interface on the same vlan.

I am starting the server with:

/opt/jagornet/jagornet-dhcpserver-2.0.0/bin/dhcpserver start -4b eth1 -4u 10.0.0.2

Here's the configuration file:

<?xml version="1.0" encoding="UTF-8"?>

<dhc:dhcpServerConfig xsi:schemaLocation="http://jagornet.com/dhcpserver.xsd" xmlns:dhc="http://jagornet.com/dhcp/xml" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">

    <v6ServerIdOption>

        <opaqueData>

            <hexValue>0001000154F4E0EC000C29B4E211</hexValue>

        </opaqueData>

    </v6ServerIdOption>

    <v4ServerIdOption>

        <!--DHCPv4 ServerID must be a local IP address-->

        <ipAddress>10.0.0.2</ipAddress>

    </v4ServerIdOption>

    <links>

        <!--Must define at least one link for client requests-->

        <link>

            <name>IPv4 Client Link 1</name>

            <!--All DHCPv4 links are defined in CIDR notation.

                 For local links, specify the interface as a

                 startup command-line option, and configure the

                 subnet for that interface's IPv4 address.-->

            <address>10.0.0.0/24</address>

            <v4ConfigOptions>

                <v4SubnetMaskOption>

                    <ipAddress>255.255.255.0</ipAddress>

                </v4SubnetMaskOption>

                <v4RoutersOption>

                    <ipAddress>10.0.0.1</ipAddress>

                </v4RoutersOption>

            </v4ConfigOptions>

            <v4AddrPools>

                <pool>

                    <range>10.0.0.100-10.0.0.199</range>

                </pool>

            </v4AddrPools>

        </link>

    </links>

</dhc:dhcpServerConfig>

Here's the log:

2015-03-02 14:39:07,200 [main] INFO  server.JagornetDhcpServer - Starting Jagornet DHCP Server

2015-03-02 14:39:07,201 [main] INFO  server.JagornetDhcpServer - Jagornet DHCP Server Community Edition 2.0.0

Copyright Jagornet Technologies, LLC 2009-2014.  All Rights Reserved.

2015-03-02 14:39:07,201 [main] INFO  server.JagornetDhcpServer - Number of available core processors: 1

2015-03-02 14:39:07,203 [main] INFO  config.DhcpServerConfiguration - Loading server configuration file: /opt/jagornet/jagornet-dhcpserver-2.0.0/conf/dhcpserver.xml

2015-03-02 14:39:07,495 [main] INFO  config.DhcpServerConfiguration - Server configuration file loaded.

2015-03-02 14:39:07,524 [main] INFO  config.DhcpServerConfiguration - Adding subnet=10.0.0.0/24 (10.0.0.0-10.0.0.255) to link map for link: name='IPv4 Client Link 1' address=10.0.0.0/24

2015-03-02 14:39:07,557 [main] INFO  server.JagornetDhcpServer - Loading application context: [com/jagornet/dhcp/context_jdbc_derby.xml, com/jagornet/dhcp/context_jdbc_datasource.xml, com/jagornet/dhcp/context_jdbc_v2schema.xml, com/jagornet/dhcp/context.xml]

2015-03-02 14:39:07,627 [main] INFO  support.ClassPathXmlApplicationContext - Refreshing org.springframework.context.support.ClassPathXmlApplicationContext@469bcf06: startup date [Mon Mar 02 14:39:07 PST 2015]; root of context hierarchy

2015-03-02 14:39:07,671 [main] INFO  xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [com/jagornet/dhcp/context_jdbc_derby.xml]

2015-03-02 14:39:07,765 [main] INFO  xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [com/jagornet/dhcp/context_jdbc_datasource.xml]

2015-03-02 14:39:07,781 [main] INFO  xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [com/jagornet/dhcp/context_jdbc_v2schema.xml]

2015-03-02 14:39:07,796 [main] INFO  xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [com/jagornet/dhcp/context.xml]

2015-03-02 14:39:07,864 [main] INFO  config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [jdbc.derby.properties]

2015-03-02 14:39:07,878 [main] INFO  support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@57cd164d: defining beans [propertyConfigurer,dataSource,iaManager,v6NaAddrBindingManager,v6TaAddrBindingManager,v6PrefixBindingManager,v4AddrBindingManager]; root of factory hierarchy

2015-03-02 14:39:08,462 [main] INFO  db.DbSchemaManager - JDBC Connection Info:

url = jdbc:derby:/opt/jagornet/jagornet-dhcpserver-2.0.0/db/derby/jagornet-dhcp

database = Apache Derby 10.8.2.2 - (1181258)

driver = Apache Derby Embedded JDBC Driver 10.8.2.2 - (1181258)

2015-03-02 14:39:08,645 [main] INFO  server.JagornetDhcpServer - Application context loaded.

2015-03-02 14:39:08,645 [main] INFO  server.JagornetDhcpServer - Loading managers from context...

2015-03-02 14:39:08,645 [main] INFO  server.JagornetDhcpServer - Initializing V6 NA Address Binding Manager

2015-03-02 14:39:08,645 [main] INFO  binding.V6AddrBindingManager - PoolsType is null for Link: IPv4 Client Link 1

2015-03-02 14:39:08,649 [main] INFO  server.JagornetDhcpServer - Initializing V6 TA Address Binding Manager

2015-03-02 14:39:08,649 [main] INFO  binding.V6AddrBindingManager - PoolsType is null for Link: IPv4 Client Link 1

2015-03-02 14:39:08,649 [main] INFO  server.JagornetDhcpServer - Initializing V6 Prefix Binding Manager

2015-03-02 14:39:08,649 [main] INFO  binding.V6PrefixBindingManagerImpl - PoolsType is null for Link: IPv4 Client Link 1

2015-03-02 14:39:08,652 [main] INFO  server.JagornetDhcpServer - Initializing V4 Address Binding Manager

2015-03-02 14:39:08,811 [main] INFO  binding.V4AddrBindingManagerImpl - Built v4 address binding pool: 10.0.0.100-10.0.0.199 size=100

2015-03-02 14:39:08,879 [main] INFO  server.JagornetDhcpServer - Managers loaded.

2015-03-02 14:39:08,888 [main] DEBUG binding.V6PrefixBindingManagerImpl - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.server.request.binding.V6PrefixBindingManagerImpl

2015-03-02 14:39:08,889 [main] DEBUG binding.V4AddrBindingManagerImpl - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.server.request.binding.V4AddrBindingManagerImpl

2015-03-02 14:39:08,889 [main] DEBUG util.DhcpConstants - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.util.DhcpConstants

2015-03-02 14:39:08,890 [main] DEBUG db.LeaseManager - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.db.LeaseManager

2015-03-02 14:39:08,890 [main] DEBUG util.Subnet - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.util.Subnet

2015-03-02 14:39:08,890 [main] DEBUG server.JagornetDhcpServer - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.server.JagornetDhcpServer

2015-03-02 14:39:08,891 [main] DEBUG binding.BaseBindingManager - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.server.request.binding.BaseBindingManager

2015-03-02 14:39:08,891 [main] DEBUG db.JdbcLeaseManager - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.db.JdbcLeaseManager

2015-03-02 14:39:08,891 [main] DEBUG db.DbSchemaManager - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.db.DbSchemaManager

2015-03-02 14:39:08,892 [main] DEBUG com.jagornet - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet

2015-03-02 14:39:08,892 [main] DEBUG binding.BaseAddrBindingManager - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.server.request.binding.BaseAddrBindingManager

2015-03-02 14:39:08,892 [main] DEBUG base.BaseDhcpOption - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.option.base.BaseDhcpOption

2015-03-02 14:39:08,892 [main] DEBUG base.BaseIpAddressListOption - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.option.base.BaseIpAddressListOption

2015-03-02 14:39:08,892 [main] DEBUG binding.V4AddressBindingPool - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.server.request.binding.V4AddressBindingPool

2015-03-02 14:39:08,893 [main] DEBUG config.DhcpServerConfiguration - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.server.config.DhcpServerConfiguration

2015-03-02 14:39:08,893 [main] DEBUG binding.V6AddrBindingManager - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.server.request.binding.V6AddrBindingManager

2015-03-02 14:39:08,893 [main] DEBUG base.BaseIpAddressOption - preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@5ba607b4, name=log4j:logger=com.jagornet.dhcp.option.base.BaseIpAddressOption

2015-03-02 14:39:08,895 [main] DEBUG server.JagornetDhcpServer - Skipping link local address: /fe80:0:0:0:20c:29ff:feb4:e211%3

2015-03-02 14:39:08,895 [main] DEBUG server.JagornetDhcpServer - Skipping link local address: /fe80:0:0:0:20c:29ff:feb4:e207%2

2015-03-02 14:39:08,895 [main] DEBUG server.JagornetDhcpServer - Skipping loopback address: /0:0:0:0:0:0:0:1%1

2015-03-02 14:39:08,895 [main] INFO  server.JagornetDhcpServer - DHCPv6 Unicast addresses: []

2015-03-02 14:39:08,895 [main] INFO  server.JagornetDhcpServer - DHCPv6 Multicast interfaces: none

2015-03-02 14:39:08,895 [main] INFO  server.JagornetDhcpServer - DHCPv6 Port number: 547

2015-03-02 14:39:08,895 [main] INFO  server.JagornetDhcpServer - DHCPv4 Unicast addresses: [/10.0.0.2]

2015-03-02 14:39:08,895 [main] INFO  server.JagornetDhcpServer - DHCPv4 Broadcast Interface: eth1

2015-03-02 14:39:08,896 [main] INFO  server.JagornetDhcpServer - DHCPv4 Port number: 67

2015-03-02 14:39:08,905 [main] INFO  netty.NettyDhcpServer - Initializing channels: corePoolSize=16 maxChannelMemorySize=1048576 maxTotalMemorySize=1048576 receiveBufferSize=307200 sendBufferSize=307200

2015-03-02 14:39:08,905 [main] INFO  netty.NettyDhcpServer - Checking for existing socket on port=547

2015-03-02 14:39:08,907 [main] INFO  netty.NettyDhcpServer - Checking for existing socket on port=67

2015-03-02 14:39:08,955 [main] INFO  netty.NettyDhcpServer - Binding New I/O datagram channel on IPv4 socket address: /10.0.0.2:67

2015-03-02 14:39:08,966 [main] INFO  netty.NettyDhcpServer - Binding New I/O datagram channel on IPv4 wildcard address: 0.0.0.0/0.0.0.0:67

Here's a tcpdump showing the request from the client arriving.

[root@c6-jagornetdhcp jagornet-dhcpserver-2.0.0]# tcpdump -i eth1 port 67

tcpdump: verbose output suppressed, use -v or -vv for full protocol decode

listening on eth1, link-type EN10MB (Ethernet), capture size 65535 bytes

14:40:36.728478 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:0c:29:f2:4a:f1 (oui Unknown), length 300

14:40:41.732458 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:0c:29:f2:4a:f1 (oui Unknown), length 300

14:40:50.735758 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:0c:29:f2:4a:f1 (oui Unknown), length 300

14:41:00.737157 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:0c:29:f2:4a:f1 (oui Unknown), length 300

14:41:11.737528 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:0c:29:f2:4a:f1 (oui Unknown), length 300

14:41:32.748272 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:0c:29:f2:4a:f1 (oui Unknown), length 300

[Greg Rabil]

Thanks for providing the detail.  It does look like everything is configured correctly.  Could you post the output from 'ifconfig'?  Trying to determine if 10.0.0.2 is assigned to eth1.  You may also try to start the server with just '-4b eth1', that is, without the '-4u' option.

Best regards,

Greg