DHCPNAK messages in log file

When I was checking log files I spotted the following log entries that were strange:

Sep  7 11:32:20 srv dhcpd: DHCPREQUEST for 1.1.1.151 from 00:40:5a:18:83:56 via eth0
Sep  7 11:32:20 srv dhcpd: DHCPACK on 1.1.1.151 to 0:4:5:1:8:5 via eth0
Sep  7 11:32:20 srv dhcpd: DHCPREQUEST for 1.1.1.151 from 0:4:5:1:8:5 via 1.1.1.10
Sep  7 11:32:20 srv dhcpd: DHCPACK on 1.1.1.151 to 0:4:5:1:8:5 via 1.1.1.10
Sep  7 11:32:20 srv dhcpd: DHCPREQUEST for 1.1.1.151 from 0:4:5:1:8:5 via 1.1.0.10: wrong network.
Sep  7 11:32:20 srv dhcpd: DHCPNAK on 1.1.1.151 to 0:4:5:1:8:5 via 1.1.0.10

The problem is that DHCP request is received three times, on two of which the answer is positive (DHCPACK) while one received negative response (DHCPNAK) and dhcpd logged the error message 'wrong network'.

The important thing is the network configuration in this specific scenario, which looks something like follows:

  +----+            +-----+              +----+
  |    |------------|     |--------------|    |
  +----+            +-----+              +----+
  Client      Firewall/DHCP relay      DHCP server
1.1.1.151    1.1.1.10     1.1.0.10       1.1.0.4

Looking into log entries, not much can be inferred. The only thing that can be seen is that third DHCPREQUEST came from 1.1.0.10 which isn't on the same network with a client requesting IP address. Sniffing the network gave a bit more information on what's happening. Analyzing the network trace the following were conclusions:

1. There are three DHCPREQUEST messages with the same transaction ID, the same destination (1.1.0.4, i.e. DHCP server) and also client IP address field within DHCP request is set to 1.1.1.151.
2. The first DHCPREQUEST comes directly from the client. It has source IP 1.1.1.151, and there is no relay field (i.e. the value is 0.0.0.0). Also, client MAC address field within DHCP request has MAC address of a given client. 
3. The second DHCP request comes from DHCP relay on the firewall. It has source set to 1.1.0.10, and relay field is properly set to 1.1.1.10, i.e. the IP address from the client's network,.
4. The third DHCP request also comes from DHCP relay on the firewall, but this time relay field is set to 1.1.0.10. This contradicts client's IP address and DHCP server rejects this request.

So, the conclusion is that client sends request to 1.1.0.4. This request is forwarded by the firewall to the server, but also intercepted by DHCP relay on the firewall that creates two proxy requests and sends them to DHCP server too, one of which is rejected.

The interesting thing, not visible in logs, is that DHCP relay upon receiving NAK from the DCHP server, generates new NAK that is broadcasted on the network where DHCP server lives. 

So, the conclusion is that firewall is wrongly configured. It should not forward DHCP requests if there is a relay agent running. Furthermore, those NAKs aren't seen by the client, only by DHCP relay that reflects them back to DHCP servers.

Još malo MaxTV-a...

Dakle, još sam malo kopao po MaxTV-u pa ću zapisati saznanja ovdje, za ubuduće. Naime, nakon što sam napisao i objavio prethodni post pokušao sam se odmah potom ponovo spojiti i gledati MaxTV. Međutim, na moje veliko iznenađenje, jednostavno nije radilo! Odlučio sam onda pričekati jutro pa ponovo, i ponovo nije radilo. Onda sam primijetio da ni prijemnik ne radi pa sam zvao tehničku podršku. Nakon nekoliko resetiranja, sve je proradilo. U tom trenutku, odlučio sam se ponovo pokušati spojiti, vidjeti da li sada radi te malo detaljnije istražiti stvari.

Prvo sam se spojio na prijemnik (STB) i isključio ga s napajanja te ga uključio. Odmah sam primjetio da šalje DHCP upit za mrežnim parametrima. I bio je uporan u tome. Zbog toga sam na brzinu podesio DHCP poslužitelj na laptopu koji mu je poslao standardnu IP adresu koju sam već znao da treba imati, te također usmjernik i DNS poslužitelj. Nakon toga, tražio je ime sap.nat.myrio.net, a potom i SRV zapis u DNS-u za ime _vqe_channel_cfg._tcp.nat.myrio.net. Taj je zanimljiv jer ime asocira da se putem njega na neki način podešavaju konfiguracije kanala! Potom je tražio još sljedeća imena:

• mds.nat.myrio.net
• webapp.nat.myrio.net
• rm.nat.myrio.net.

Ok, digao sam DNS i podmetnuo mu ime webapp.nat.myrio.net. Na moje iznenađenje, potom se je pokušao spojiti na port 80. Naravno, na portu 80 nije bilo ničega. Prvo sam mislio dići Apache, ali sam onda ipak samo pokrenuo netcat koji je snimio sljedeći zahtjev:

GET /broker/documentName=GLOBALINSTALL.xml.gz HTTP/1.1
Accept: text/html, text/plain, text/*;q=0.8, image/gif, image/jpeg, image/*;q=0.8, */*;q=0.2
Accept-Encoding: gzip;q=1.0, x-gzip, deflate;q=1.0, identity;q=0.8
Host: webapp.nat.myrio.net
Connection: Keep-Alive, TE
TE: gzip, x-gzip, deflate

Zanimljivo, zar ne. :)

Tu sam stao s tim eksperimentima. Onda sam se spojio kao prijemnik na T-Com i pokušao dobiti IP adresu koristeći program dhclient:

dhclient em1

Međutim, nije bilo odgovora. Očito je tražio nešto specifično bez čega nije htio odgovoriti. Prvo sam mislio da je u pitanju MAC adresa, ali nije bila. Nakon petljanja i pregledavanja zahtjeva koji sam snimio dok sam bio priključen na STB, skužio sam da zahtjeva opciju VENDOR sa točno određenim sadržajem, tj. ako se naredba pozove ovako:

dhclient -V albis_7710 em1

uredno dobijem IP adresu i sve ostale parametre. Dakle, priča da T-Com prati MAC adrese ne stoji. Dalje sam petljao sa zahtjevima Web poslužitelju, došao do nekih podataka o kojima za sada neću i na kraju opet zaključio da najveći napredak sada mogu postići ako se spojim između STB-a i T-Com-a.

Još par stvari prije kraja:

• Moguće je istovremeno pratiti dva programa putem MaxTV-a. Jedini problem koji sam imao je da, iz nekog razloga, Linux kernel je objema aplikacijama slao sve difuzne pakete, tj. nije ih razdvajao prema pristupu!
• Snimanje programa je trivijalno. dumpstream opcija mplayera snima savršeno. :)
• Opet nisam uspio do stranih kanala.
• Po veličini prozora koji se ostvara za prikaz videa jasno se raspoznaje "običan" od HD kanala.

Nastavak možete potražiti u ovom postu.

Searching for packet catpuring and interface manipulation library for Python...

I needed a script that would monitor network traffic and capture and process only DHCP traffic. It turned out I couldn't find such script so I decided to write one (more about that script in another post). For a language I decided to use Python. That was the easy part. Now, I had to decide which libraries I will use that will allow me to capture network traffic, decode DHCP request and responses, and manipulate IP addresses on interfaces.

I started with the network traffic capturing. pcap library is the library for network capture, so it was natural for me to search for a Python interface to this library. I found several such interfaces, i.e. pcap, pylibpcap, pypcap, and pcapy. There is also library interface specifically for Python 3, i.e. py3kcap. While searching for pcap interface, three other Python libraries poped out: libdnet (here is the old project page), dpkt and scapy.

But, not all libraries are equal, nor they serve the same purpose. libdnet allows sending packets, manipulation with kernel's routing tables, firewall and arp cache. So, besides Ethernet and IP, it doesn't offer much more in term of supported protocols. dpkt, on the other hand, is made just for this purpose! It supports easy creation and parsing of different TCP/IP protocols. Finally, Scapy is a swiss army knife of network manipulation. It offers shell in which one can manipulate packets, but also can be used within other scripts. Unfortunately, while browsing the source of Scapy I realized that it uses os.popen interface and calls external programs. So, this actually was enough for me to eliminate scapy from further consideration.

The next elimination criteria is availability of the packages within CentOS and Fedora. I try to hold on prepackaged software as much as possible, so quick search (yum search) showed that on both, CentOS 6 and Fedora 17, there are packages for pcapy and dpkt (named python-dpkt). For some reason, there is dnet, but python interface isn't packaged. I found this bugzilla entry, but without any answer!

So, I settled on pcapy and dpkt. The only piece of puzzle that was missing now is how to manipulate interface addresses. I stumbled on netifaces, which allows me to obtain information about interfaces and also on this post for Windows. But all the results I got were on how to obtain IP address. In the end, I gave up and decided that I'll try to use libdnet even though I'll have to compile it from the source. Either that, or I'll use raw sockets and ioctls which are accessible from Python using standard libraries.

And for the end, as a curiosity, I'll mention that there is Python interface to IPTables, python-iptables, which is also packaged for Fedora.

Another internal error trying to access IPA Web UI

I just tried to access IPA's Web UI and I got 'Internal Server Error' dialog box:

Looking into log file (/var/log/httpd/error_log) I found the following entry that obviously was the reason dialog box appeared:

[Thu Jun 28 21:10:28 2012] [error] [client 192.168.178.1] gss_acquire_cred() failed: Unspecified GSS failure.  Minor code may provide more information (, No key table entry found for HTTP/ipa.example-domain.local.localdomain@EXAMPLE-DOMAIN.HR), referer: https://ipa.example-domain.local/ipa/ui/

It's immediately obvious that something is wrong with the name of IPA server and that somehow .localdomain was appended!? At first, I thought that the problem is in the Firefox and that the value of keys network.negotiate-auth.trusted-uris and network.negotiate-auth.delegation-uris have to end with a dot so that no domain is appended. But quick test showed that I was wrong, when I added dots there nothing worked any more. :)

So, I thought that there must be something on a server that causes that behavior. And then, I looked into /etc/resolv.conf and there it was:

search localdomain example-domain.local

So, this search statement cause localdomain to be appended to the IPA's FQDN. So, I removed that statement and tried again, but the error was still there. Then, it occured to me that Apache probably memorized the statement so I restarted it. And, lo and behold, everyting worked.

You might wonder from where came this search statement. Well, I play tricks with my network setup, and in this case DHCP was used to obtain list of DNS servers which later I manually changed into 127.0.0.1. But, I forgot to remove search statement and so the error occurred. Playing games with network setup obviously bites sometimes... ;)