No DHCPv6 on internal net, radvd issue: "sendmsg: Permission denied"



  • I'm running 2.1-RC0 (i386) built on Fri Jul 12 10:55:10 EDT 2013 and I'm just trying to IPv6-enable my home network.

    I got a HE-tunnel with a /48 subnet. I'm quite sure that I did the IPv6 setup correctly because I can ping from the pfsense internal IPv6 adress to IPv6-only hosts in the internet and vice versa.
    So everything works so far but it seems that there are no IPv6 adresses assigned to the internal clients. I assigned a /96 subnet (from the /48 net) to the internal interface and set up the DHCPv6 server to provide a subset of IP adresses of that net. I set up RA to "managed" or "assisted"- none works.

    In the System–>routing logs i gotthe following:

    Jul 13 11:47:41 pfsense radvd[54107]: timer_handler called for bge1
    Jul 13 11:47:41 pfsense radvd[54107]: sending RA on bge1
    Jul 13 11:47:41 pfsense radvd[54107]: adding prefix 2001:470:723c:20:: to advert for bge1
    Jul 13 11:47:41 pfsense radvd[54107]: using if_index 3 for interface bge1
    Jul 13 11:47:41 pfsense radvd[54107]: sendmsg: [color]Permission denied[/color]
    Jul 13 11:47:41 pfsense radvd[54107]: polling for 7.727 seconds.
    Jul 13 11:47:41 pfsense radvd[54107]: recvmsg len=128
    Jul 13 11:47:41 pfsense radvd[54107]: if_index 3
    Jul 13 11:47:41 pfsense radvd[54107]: found Interface: bge1
    Jul 13 11:47:41 pfsense radvd[54107]: received RA from fe80::210:18ff:fe06:e4df
    Jul 13 11:47:41 pfsense radvd[54107]: polling for 7.588 seconds.
    

    Despite of already using an any-any accept rule on internal IF, I thought it is a conflict with the firewall. I disabled it via System–>Advanced-->Firewall/NAT and voila I got an IPv6 address on my client. I enabled the firewall and it still worked.

    So I did the reboot-test of pfsense and everything failed. Even disabeling the firewall did not work anymore.

    I "truss"-ed the radvd - I see the failures but I can't figure out why it is failing:

    0.000111468 __sysctl(0xbfbfe544,0x2,0xbfbfe54c,0xbfbfe550,0x0,0x0) = 0 (0x0)
    0.197086776 mmap(0x0,328,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 671694848 (0x28094000)
    0.200223807 munmap(0x28094000,328)		 = 0 (0x0)
    0.204176315 __sysctl(0xbfbfe5a8,0x2,0x2808ae3c,0xbfbfe5b0,0x0,0x0) = 0 (0x0)
    0.207169751 mmap(0x0,32768,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 671694848 (0x28094000)
    0.211141815 issetugid(0x28083fef,0xbfbfea6c,0x104,0x0,0x0,0x0) = 0 (0x0)
    0.214484461 open("/etc/libmap.conf",O_RDONLY,0666) = 3 (0x3)
    0.219921254 fstat(3,{ mode=-rw-r--r-- ,inode=227247,size=106,blksize=4096 }) = 0 (0x0)
    0.224919719 read(3,"libc.so.5\t\tlibc.so.6\nlibssl.so.4     libssl.so.5\nlibcrypto.so.4  libcrypto.so.5\nlibz.so.3       libz.so.4\n",4096) = 106 (0x6a)
    0.230068204 read(3,0x28098000,4096)		 = 0 (0x0)
    0.235160536 close(3)				 = 0 (0x0)
    0.240248119 open("/var/run/ld-elf.so.hints",O_RDONLY,00) = 3 (0x3)
    0.245188195 read(3,"Ehnt\^A\0\0\0\M^@\0\0\0\M-f\^C\0\0\0\0\0\0\M-e\^C\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,128) = 128 (0x80)
    0.250459044 lseek(3,0x80,SEEK_SET)		 = 128 (0x80)
    0.255619542 read(3,"/usr/lib:/usr/local/lib:/lib:/usr/pbi/arping-i386/lib:/usr/pbi/arping-i386/lib/X11:/usr/pbi/bandwidthd-i386/lib:/usr/pbi/bandwidthd-i386/lib/X11:/usr/"...,998) = 998 (0x3e6)
    0.260586438 close(3)				 = 0 (0x0)
    0.265641893 access("/usr/lib/libdaemon.so.0",0)	 ERR#2 'No such file or directory'
    0.270728638 access("/usr/local/lib/libdaemon.so.0",0) = 0 (0x0)
    0.275635470 mmap(0x0,36864,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 671727616 (0x2809c000)
    0.280643433 open("/usr/local/lib/libdaemon.so.0",O_RDONLY,00) = 3 (0x3)
    0.285701961 fstat(3,{ mode=-rwxr-xr-x ,inode=112662,size=24383,blksize=4096 }) = 0 (0x0)
    0.290678076 pread(0x3,0x28089d80,0x1000,0x0,0x0,0x0) = 4096 (0x1000)
    0.295827679 mmap(0x0,24576,PROT_NONE,MAP_PRIVATE|MAP_ANON|MAP_NOCORE,-1,0x0) = 671764480 (0x280a5000)
    0.300881458 mmap(0x280a5000,20480,PROT_READ|PROT_EXEC,MAP_PRIVATE|MAP_FIXED|MAP_NOCORE,3,0x0) = 671764480 (0x280a5000)
    0.305847515 mmap(0x280aa000,4096,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED,3,0x4000) = 671784960 (0x280aa000)
    0.311072268 close(3)				 = 0 (0x0)
    0.316061234 access("/usr/lib/libc.so.7",0)	 ERR#2 'No such file or directory'
    0.321422878 access("/usr/local/lib/libc.so.7",0) ERR#2 'No such file or directory'
    0.326254838 access("/lib/libc.so.7",0)		 = 0 (0x0)
    0.331500544 open("/lib/libc.so.7",O_RDONLY,027757762634) = 3 (0x3)
    0.336736471 fstat(3,{ mode=-r--r--r-- ,inode=63665,size=1095964,blksize=4096 }) = 0 (0x0)
    0.341891382 pread(0x3,0x28089d80,0x1000,0x0,0x0,0x0) = 4096 (0x1000)
    0.346740943 mmap(0x0,1093632,PROT_NONE,MAP_PRIVATE|MAP_ANON|MAP_NOCORE,-1,0x0) = 671789056 (0x280ab000)
    0.351909543 mmap(0x280ab000,978944,PROT_READ|PROT_EXEC,MAP_PRIVATE|MAP_FIXED|MAP_NOCORE,3,0x0) = 671789056 (0x280ab000)
    0.358273841 mmap(0x2819a000,24576,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED,3,0xef000) = 672768000 (0x2819a000)
    0.361504739 mmap(0x281a0000,90112,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED|MAP_ANON,-1,0x0) = 672792576 (0x281a0000)
    0.366902142 close(3)				 = 0 (0x0)
    0.371848085 mmap(0x0,768,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 672882688 (0x281b6000)
    0.377126477 munmap(0x281b6000,768)		 = 0 (0x0)
    0.382248143 mmap(0x0,872,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 672882688 (0x281b6000)
    0.387501391 munmap(0x281b6000,872)		 = 0 (0x0)
    0.392500414 mmap(0x0,21552,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 672882688 (0x281b6000)
    0.397737739 munmap(0x281b6000,21552)		 = 0 (0x0)
    0.402938187 sysarch(0xa,0xbfbfe610,0x2805a41b,0x280892f8,0x2806cbc9,0x280892f8) = 0 (0x0)
    0.408295081 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
    0.413440214 sigprocmask(SIG_SETMASK,0x0,0x0)	 = 0 (0x0)
    0.418640382 __sysctl(0xbfbfe5c4,0x2,0x281a0a20,0xbfbfe5cc,0x0,0x0) = 0 (0x0)
    0.423972971 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
    0.429998395 sigprocmask(SIG_SETMASK,0x0,0x0)	 = 0 (0x0)
    0.434082486 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
    0.437283213 sigprocmask(SIG_SETMASK,0x0,0x0)	 = 0 (0x0)
    0.441458098 clock_gettime(13,{1373709999.000000000 }) = 0 (0x0)
    0.637784154 clock_gettime(13,{1373710000.000000000 }) = 0 (0x0)
    0.645106965 __sysctl(0xbfbfd0f4,0x2,0x281a5780,0xbfbfd0fc,0x0,0x0) = 0 (0x0)
    0.649706491 __sysctl(0xbfbfd014,0x2,0xbfbfcfac,0xbfbfd01c,0x281933b4,0xc) = 0 (0x0)
    0.655198879 __sysctl(0xbfbfcfac,0x2,0x281a5878,0xbfbfd058,0x0,0x0) = 0 (0x0)
    0.661603406 readlink("/etc/malloc.conf",0xbfbfd103,1024) ERR#2 'No such file or directory'
    0.668123591 issetugid(0x281920b9,0xbfbfd103,0x400,0xbfbfd0fc,0x0,0x0) = 0 (0x0)
    0.674310211 break(0x8100000)			 = 0 (0x0)
    0.680858054 __sysctl(0xbfbfd384,0x2,0xbfbfd38c,0xbfbfd390,0x0,0x0) = 0 (0x0)
    0.687181005 mmap(0x0,1048576,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 672882688 (0x281b6000)
    0.693819922 mmap(0x282b6000,303104,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 673931264 (0x282b6000)
    0.700147902 munmap(0x281b6000,303104)		 = 0 (0x0)
    0.706745752 access("/etc/localtime",4)		 = 0 (0x0)
    0.712986568 open("/etc/localtime",O_RDONLY,05002262000) = 3 (0x3)
    0.719815456 fstat(3,{ mode=-rw-r--r-- ,inode=227099,size=2309,blksize=4096 }) = 0 (0x0)
    0.726117734 read(3,"TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\b\0\0\0\b\0\0\0\0\0\0\0\M^P\0\0\0\b\0\0\0\^N\M^[\f\^W`\M^[\M-U\M-Z\M-p\M^\\M-Y\M-.\M^P\M^]\M-$\M-5\M^P\M^^"...,29000) = 2309 (0x905)
    0.733388024 close(3)				 = 0 (0x0)
    0.739826914 getpid()				 = 78607 (0x1330f)
    0.746474770 socket(PF_LOCAL,SOCK_DGRAM,0)	 = 3 (0x3)
    0.752859742 fcntl(3,F_SETFD,FD_CLOEXEC)		 = 0 (0x0)
    0.759426861 connect(3,{ AF_UNIX "/var/run/logpriv" },106) = 0 (0x0)
    0.766138135 sendto(3,"<30>Jul 13 12:06:40 radvd[78607]: version 1.9.1 started",55,0x0,NULL,0x0) = 55 (0x37)
    0.772736823 socket(PF_INET6,SOCK_RAW,58)	 = 4 (0x4)
    0.778987976 setsockopt(0x4,0x29,0x24,0xbfbfeb3c,0x4,0x2819e078) = 0 (0x0)
    0.785569064 setsockopt(0x4,0x29,0x1a,0xbfbfeb3c,0x4,0x2819e078) = 0 (0x0)
    0.791916320 setsockopt(0x4,0x29,0x4,0xbfbfeb3c,0x4,0x2819e078) = 0 (0x0)
    0.798720065 setsockopt(0x4,0x29,0xa,0xbfbfeb3c,0x4,0x2819e078) = 0 (0x0)
    0.805256174 setsockopt(0x4,0x29,0x25,0xbfbfeb3c,0x4,0x2819e078) = 0 (0x0)
    0.811985327 setsockopt(0x4,0x3a,0x12,0xbfbfeb1c,0x20,0x2819e078) = 0 (0x0)
    0.818606924 open("/var/etc/radvd.conf",O_RDONLY,0666) = 5 (0x5)
    0.825307581 close(5)				 = 0 (0x0)
    0.831638634 stat("/etc/nsswitch.conf",{ mode=-rw-r--r-- ,inode=227118,size=328,blksize=4096 }) = 0 (0x0)
    1.026304681 open("/etc/nsswitch.conf",O_RDONLY,0666) = 5 (0x5)
    1.033406791 ioctl(5,TIOCGETA,0xbfbfe830)	 ERR#25 'Inappropriate ioctl for device'
    1.038836880 fstat(5,{ mode=-rw-r--r-- ,inode=227118,size=328,blksize=4096 }) = 0 (0x0)
    1.044816487 read(5,"#\n# nsswitch.conf(5) - name service switch configuration file\n# $FreeBSD: src/etc/nsswitch.conf,v 1.1.10.1.8.2 2012/11/17 08:24:37 svnexp Exp $\n#\n"...,4096) = 328 (0x148)
    1.051700969 read(5,0x28221000,4096)		 = 0 (0x0)
    1.058263619 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
    1.064901698 access("/usr/lib/nss_files.so.1",0)	 ERR#2 'No such file or directory'
    1.071410708 access("/usr/local/lib/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.078042362 access("/lib/nss_files.so.1",0)	 ERR#2 'No such file or directory'
    1.084376767 access("/usr/pbi/arping-i386/lib/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.091104524 access("/usr/pbi/arping-i386/lib/X11/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.097632252 access("/usr/pbi/bandwidthd-i386/lib/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.296610913 access("/usr/pbi/bandwidthd-i386/lib/X11/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.299862485 access("/usr/pbi/bandwidthd-i386/lib/gettext/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.303961661 access("/usr/pbi/bandwidthd-i386/lib/libpng/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.307103721 access("/usr/pbi/bandwidthd-i386/lib/postgresql/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.310957053 access("/usr/pbi/zip-i386/lib/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.317139482 access("/usr/pbi/zip-i386/lib/X11/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.323318558 access("/usr/pbi/p7zip-i386/lib/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.329448186 access("/usr/pbi/p7zip-i386/lib/X11/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.335530321 access("/usr/pbi/dansguardian-i386/lib/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.341654641 access("/usr/pbi/dansguardian-i386/lib/X11/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.347729513 access("/usr/pbi/dansguardian-i386/lib/apr-util-1/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.361045062 access("/usr/pbi/dansguardian-i386/lib/arj/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.367259339 access("/usr/pbi/dansguardian-i386/lib/db42/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.373550442 access("/usr/pbi/dansguardian-i386/lib/gettext/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.379566087 access("/usr/pbi/dansguardian-i386/lib/perl5/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.385648782 access("/usr/pbi/freeradius-i386/lib/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.391982069 access("/usr/pbi/freeradius-i386/lib/X11/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.398149692 access("/usr/pbi/freeradius-i386/lib/freeradius-2.2.0/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.404231268 access("/usr/pbi/freeradius-i386/lib/gettext/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.410452529 access("/usr/pbi/freeradius-i386/lib/krb5/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.416458397 access("/usr/pbi/freeradius-i386/lib/libpng/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.422730782 access("/usr/pbi/freeradius-i386/lib/mysql/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.428719608 access("/usr/pbi/freeradius-i386/lib/perl5/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.434762074 access("/usr/pbi/freeradius-i386/lib/postgresql/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.440954839 access("/usr/pbi/freeradius-i386/lib/python2.7/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.446863207 access("/usr/local/lib/mysql/nss_files.so.1",0) ERR#2 'No such file or directory'
    1.454087681 access("/lib/nss_files.so.1",0)	 ERR#2 'No such file or directory'
    1.458958474 access("/usr/lib/nss_files.so.1",0)	 ERR#2 'No such file or directory'
    1.464511764 sigprocmask(SIG_SETMASK,0x0,0x0)	 = 0 (0x0)
    1.470985295 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
    1.477177502 access("/usr/lib/nss_dns.so.1",0)	 ERR#2 'No such file or directory'
    1.483334508 access("/usr/local/lib/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.489411614 access("/lib/nss_dns.so.1",0)	 ERR#2 'No such file or directory'
    1.495674781 access("/usr/pbi/arping-i386/lib/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.501869222 access("/usr/pbi/arping-i386/lib/X11/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.508001365 access("/usr/pbi/bandwidthd-i386/lib/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.514190778 access("/usr/pbi/bandwidthd-i386/lib/X11/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.522006675 access("/usr/pbi/bandwidthd-i386/lib/gettext/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.528589718 access("/usr/pbi/bandwidthd-i386/lib/libpng/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.545349045 access("/usr/pbi/bandwidthd-i386/lib/postgresql/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.548505352 access("/usr/pbi/zip-i386/lib/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.552375447 access("/usr/pbi/zip-i386/lib/X11/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.555469734 access("/usr/pbi/p7zip-i386/lib/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.559435093 access("/usr/pbi/p7zip-i386/lib/X11/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.562584975 access("/usr/pbi/dansguardian-i386/lib/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.568229339 access("/usr/pbi/dansguardian-i386/lib/X11/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.575034201 access("/usr/pbi/dansguardian-i386/lib/apr-util-1/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.581581486 access("/usr/pbi/dansguardian-i386/lib/arj/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.588186320 access("/usr/pbi/dansguardian-i386/lib/db42/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.594740588 access("/usr/pbi/dansguardian-i386/lib/gettext/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.601215236 access("/usr/pbi/dansguardian-i386/lib/perl5/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.790047226 access("/usr/pbi/freeradius-i386/lib/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.797134251 access("/usr/pbi/freeradius-i386/lib/X11/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.802498967 access("/usr/pbi/freeradius-i386/lib/freeradius-2.2.0/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.808193060 access("/usr/pbi/freeradius-i386/lib/gettext/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.815042062 access("/usr/pbi/freeradius-i386/lib/krb5/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.821420887 access("/usr/pbi/freeradius-i386/lib/libpng/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.827933809 access("/usr/pbi/freeradius-i386/lib/mysql/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.834190270 access("/usr/pbi/freeradius-i386/lib/perl5/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.841001837 access("/usr/pbi/freeradius-i386/lib/postgresql/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.847445755 access("/usr/pbi/freeradius-i386/lib/python2.7/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.854083834 access("/usr/local/lib/mysql/nss_dns.so.1",0) ERR#2 'No such file or directory'
    1.860516018 access("/lib/nss_dns.so.1",0)	 ERR#2 'No such file or directory'
    1.867435701 access("/usr/lib/nss_dns.so.1",0)	 ERR#2 'No such file or directory'
    1.873973207 sigprocmask(SIG_SETMASK,0x0,0x0)	 = 0 (0x0)
    1.880618270 ioctl(5,TIOCGETA,0xbfbfe830)	 ERR#25 'Inappropriate ioctl for device'
    1.886950999 close(5)				 = 0 (0x0)
    1.893707810 geteuid()				 = 0 (0x0)
    1.900008971 open("/etc/spwd.db",O_RDONLY,00)	 = 5 (0x5)
    1.906635595 fcntl(5,F_SETFD,FD_CLOEXEC)		 = 0 (0x0)
    1.913343237 fstat(5,{ mode=-rw------- ,inode=227414,size=40960,blksize=4096 }) = 0 (0x0)
    1.920169611 read(5,"\0\^F\^Ua\0\0\0\^B\0\0\^D\M-R\0\0\^P\0\0\0\0\f\0\0\^A\0\0\0\^A\0\0\0\0\b\0\0\0\^C\0\0\0\^B\0\0\0\a\0\0\0\^O\0\0\0\a\0\0\0 \0\0\0\M-;\0\0\0\^A\M^Un}"...,260) = 260 (0x104)
    1.927175898 pread(0x5,0x28232000,0x1000,0x6000,0x0,0xc) = 4096 (0x1000)
    1.934033002 close(5)				 = 0 (0x0)
    1.940381375 stat("/var/etc/radvd.conf",{ mode=-rw-r--r-- ,inode=16149,size=451,blksize=16384 }) = 0 (0x0)
    1.946989283 __sysctl(0xbfbfeb30,0x4,0xbfbfeb44,0xbfbfeb40,0x0,0x0) = 0 (0x0)
    1.961230939 open("/var/etc/radvd.conf",O_RDONLY,0666) = 5 (0x5)
    1.967920701 ioctl(5,TIOCGETA,0xbfbfe170)	 ERR#25 'Inappropriate ioctl for device'
    1.974381660 fstat(5,{ mode=-rw-r--r-- ,inode=16149,size=451,blksize=16384 }) = 0 (0x0)
    1.981094331 read(5,"# Automatically Generated, do not edit\n# Generated for DHCPv6 Server lan\ninterface bge1 {\n\tAdvSendAdvert on;\n\tMinRtrAdvInterval 5;\n\tMaxRtrAdvI"...,16384) = 451 (0x1c3)
    1.987661171 read(5,0x2822f000,16384)		 = 0 (0x0)
    1.994556548 ioctl(4,SIOCGVH,0xbfbfe220)		 ERR#22 'Invalid argument'
    2.000837594 ioctl(4,SIOCGIFFLAGS,0xbfbfe220)	 = 0 (0x0)
    2.007750851 socket(PF_INET,SOCK_DGRAM,0)	 = 6 (0x6)
    2.015194909 ioctl(6,SIOCGIFINDEX,0xbfbfe198)	 = 0 (0x0)
    2.019164458 close(6)				 = 0 (0x0)
    2.022238910 ioctl(4,SIOCGIFMTU,0xbfbfe208)	 = 0 (0x0)
    2.026164040 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.029283750 getpid()				 = 78607 (0x1330f)
    2.033370914 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: mtu for bge1 is 1500",54,0x0,NULL,0x0) = 54 (0x36)
    2.036747084 __sysctl(0xbfbfe1a0,0x6,0x0,0xbfbfe1b8,0x0,0x0) = 0 (0x0)
    2.040827823 __sysctl(0xbfbfe1a0,0x6,0x28239a00,0xbfbfe1b8,0x0,0x0) = 0 (0x0)
    2.046368262 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.053456963 getpid()				 = 78607 (0x1330f)
    2.059082889 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: link layer token length for bge1 is 48",72,0x0,NULL,0x0) = 72 (0x48)
    2.066053137 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.071417295 getpid()				 = 78607 (0x1330f)
    2.078526390 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: prefix length for bge1 is 64",62,0x0,NULL,0x0) = 62 (0x3e)
    2.084017660 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.090815818 getpid()				 = 78607 (0x1330f)
    2.096548742 sendto(3,"<28>Jul 13 12:06:41 radvd[78607]: prefix length should be 64 for bge1",69,0x0,NULL,0x0) = 69 (0x45)
    2.276310190 __sysctl(0xbfbfe1d0,0x6,0x0,0xbfbfe1e8,0x0,0x0) = 0 (0x0)
    2.282763606 __sysctl(0xbfbfe1d0,0x6,0x28239a00,0xbfbfe1e8,0x0,0x0) = 0 (0x0)
    2.288270522 setsockopt(0x4,0x29,0xd,0xbfbfe22c,0x14,0x0) ERR#49 'Can't assign requested address'
    2.293194953 setsockopt(0x4,0x29,0xc,0xbfbfe22c,0x14,0x0) = 0 (0x0)
    2.300134191 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.305439961 getpid()				 = 78607 (0x1330f)
    2.312269687 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: interface definition for bge1 is ok",69,0x0,NULL,0x0) = 69 (0x45)
    2.317519863 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.324398199 getpid()				 = 78607 (0x1330f)
    2.329874942 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: bge1: if_index 3",50,0x0,NULL,0x0) = 50 (0x32)
    2.336587054 ioctl(5,TIOCGETA,0xbfbfe170)	 ERR#25 'Inappropriate ioctl for device'
    2.341989765 close(5)				 = 0 (0x0)
    2.348980686 sigaction(SIGHUP,{ 0x804dc70 SA_RESTART ss_t },{ SIG_DFL 0x0 ss_t }) = 0 (0x0)
    2.354460503 sigaction(SIGTERM,{ 0x804dde0 SA_RESTART ss_t },{ SIG_DFL SA_RESTART ss_t }) = 0 (0x0)
    2.361191891 sigaction(SIGINT,{ 0x804dda0 SA_RESTART ss_t },{ SIG_DFL SA_RESTART ss_t }) = 0 (0x0)
    2.367413710 sigaction(SIGUSR1,{ 0x804dc40 SA_RESTART ss_t },{ SIG_DFL 0x0 ss_t }) = 0 (0x0)
    2.372838771 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.377683303 getpid()				 = 78607 (0x1330f)
    2.384616116 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: setting LinkMTU (1500) for bge1 is not supported",82,0x0,NULL,0x0) = 82 (0x52)
    2.389972172 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.396687077 getpid()				 = 78607 (0x1330f)
    2.402313842 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: setting CurHopLimit (64) for bge1 is not supported",84,0x0,NULL,0x0) = 84 (0x54)
    2.408985445 gettimeofday({1373710001.823573 },0x0) = 0 (0x0)
    2.414486494 gettimeofday({1373710001.829073 },0x0) = 0 (0x0)
    2.421475180 ioctl(4,SIOCGIFFLAGS,0xbfbfe380)	 = 0 (0x0)
    2.426823135 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.433521278 getpid()				 = 78607 (0x1330f)
    2.439026517 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: sending RA on bge1",52,0x0,NULL,0x0) = 52 (0x34)
    2.445860992 gettimeofday({1373710001.860448 },0x0) = 0 (0x0)
    2.451315945 gettimeofday({1373710001.865902 },0x0) = 0 (0x0)
    2.458264961 __sysctl(0xbfbfe390,0x4,0xbfbfe3a4,0xbfbfe3a0,0x0,0x0) = 0 (0x0)
    2.463659850 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.470585399 getpid()				 = 78607 (0x1330f)
    2.476149026 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: adding prefix 2001:470:723c:20:: to advert for bge1",85,0x0,NULL,0x0) = 85 (0x55)
    2.482926790 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.488552436 getpid()				 = 78607 (0x1330f)
    2.495548666 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: using if_index 3 for interface bge1",69,0x0,NULL,0x0) = 69 (0x45)
    2.501111176 sendmsg(0x4,0xbfbfea2c,0x0,0x3,0x28233100,0x200) ERR#13 'Permission denied'
    2.509104472 stat("/usr/share/nls/C/libc.cat",0xbfbfdea4) ERR#2 'No such file or directory'
    2.512322520 stat("/usr/share/nls/libc/C",0xbfbfdea4) ERR#2 'No such file or directory'
    2.516218875 stat("/usr/local/share/nls/C/libc.cat",0xbfbfdea4) ERR#2 'No such file or directory'
    2.519431335 stat("/usr/local/share/nls/libc/C",0xbfbfdea4) ERR#2 'No such file or directory'
    2.523450892 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.526764483 getpid()				 = 78607 (0x1330f)
    2.530860307 sendto(3,"<28>Jul 13 12:06:41 radvd[78607]: sendmsg: Permission denied",60,0x0,NULL,0x0) = 60 (0x3c)
    2.535766580 gettimeofday({1373710001.950354 },0x0) = 0 (0x0)
    2.542913110 socket(PF_ROUTE,SOCK_RAW,0)		 = 5 (0x5)
    2.548697997 gettimeofday({1373710001.963285 },0x0) = 0 (0x0)
    2.555743954 gettimeofday({1373710001.970331 },0x0) = 0 (0x0)
    2.569078221 clock_gettime(13,{1373710001.000000000 }) = 0 (0x0)
    2.576126972 getpid()				 = 78607 (0x1330f)
    2.582291800 sendto(3,"<31>Jul 13 12:06:41 radvd[78607]: polling for 15.981 seconds.",61,0x0,NULL,0x0) = 61 (0x3d)
    2.589301999 poll({4/POLLIN 5/POLLIN},2,15981)	 = 1 (0x1)
    2.595152817 select(5,{4},0x0,0x0,0x0)		 = 1 (0x1)
    2.602243752 recvmsg(0x4,0xbfbfe4d8,0x0,0x0,0x0,0x28096400) = 128 (0x80)
    2.608284262 clock_gettime(13,{1373710002.000000000 }) = 0 (0x0)
    2.615335247 getpid()				 = 78607 (0x1330f)
    2.621412354 sendto(3,"<31>Jul 13 12:06:42 radvd[78607]: recvmsg len=128",49,0x0,NULL,0x0) = 49 (0x31)
    2.628466692 clock_gettime(13,{1373710002.000000000 }) = 0 (0x0)
    2.634316393 getpid()				 = 78607 (0x1330f)
    2.641768552 sendto(3,"<31>Jul 13 12:06:42 radvd[78607]: if_index 3",44,0x0,NULL,0x0) = 44 (0x2c)
    2.647736426 clock_gettime(13,{1373710002.000000000 }) = 0 (0x0)
    2.655025993 getpid()				 = 78607 (0x1330f)
    2.661254238 sendto(3,"<31>Jul 13 12:06:42 radvd[78607]: found Interface: bge1",55,0x0,NULL,0x0) = 55 (0x37)
    2.668504693 clock_gettime(13,{1373710002.000000000 }) = 0 (0x0)
    2.674694106 getpid()				 = 78607 (0x1330f)
    2.681973057 sendto(3,"<31>Jul 13 12:06:42 radvd[78607]: received RA from fe80::210:18ff:fe06:e4df",75,0x0,NULL,0x0) = 75 (0x4b)
    2.687848180 gettimeofday({1373710002.102435 },0x0) = 0 (0x0)
    2.694872346 gettimeofday({1373710002.109459 },0x0) = 0 (0x0)
    2.700737133 clock_gettime(13,{1373710002.000000000 }) = 0 (0x0)
    2.879168226 getpid()				 = 78607 (0x1330f)
    2.885952694 sendto(3,"<31>Jul 13 12:06:42 radvd[78607]: polling for 15.84 seconds.",60,0x0,NULL,0x0) = 60 (0x3c)
    18.737064351 poll({4/POLLIN 5/POLLIN},2,15840)	 = 0 (0x0)
    18.742048569 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    18.749246505 getpid()				 = 78607 (0x1330f)
    18.755387310 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: timer_handler called for bge1",63,0x0,NULL,0x0) = 63 (0x3f)
    18.762357840 ioctl(4,SIOCGIFFLAGS,0xbfbfdd40)	 = 0 (0x0)
    18.768452828 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    18.963625709 getpid()				 = 78607 (0x1330f)
    18.970450967 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: sending RA on bge1",52,0x0,NULL,0x0) = 52 (0x34)
    18.976376379 gettimeofday({1373710018.390963 },0x0) = 0 (0x0)
    18.981597222 gettimeofday({1373710018.396184 },0x0) = 0 (0x0)
    18.988976468 __sysctl(0xbfbfdd50,0x4,0xbfbfdd64,0xbfbfdd60,0x0,0x0) = 0 (0x0)
    18.994904674 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    19.002197316 getpid()				 = 78607 (0x1330f)
    19.008464674 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: adding prefix 2001:470:723c:20:: to advert for bge1",85,0x0,NULL,0x0) = 85 (0x55)
    19.015765418 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    19.021826323 getpid()				 = 78607 (0x1330f)
    19.028942963 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: using if_index 3 for interface bge1",69,0x0,NULL,0x0) = 69 (0x45)
    19.035073431 sendmsg(0x4,0xbfbfe3ec,0x0,0x3,0x28233100,0x2) ERR#13 'Permission denied'
    19.042171074 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    19.048139229 getpid()				 = 78607 (0x1330f)
    19.055491935 sendto(3,"<28>Jul 13 12:06:58 radvd[78607]: sendmsg: Permission denied",60,0x0,NULL,0x0) = 60 (0x3c)
    19.061514008 gettimeofday({1373710018.476101 },0x0) = 0 (0x0)
    19.068698255 gettimeofday({1373710018.483285 },0x0) = 0 (0x0)
    19.075703985 gettimeofday({1373710018.490291 },0x0) = 0 (0x0)
    19.079491667 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    19.082742961 getpid()				 = 78607 (0x1330f)
    19.086901364 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: polling for 7.411 seconds.",60,0x0,NULL,0x0) = 60 (0x3c)
    19.090124442 poll({4/POLLIN 5/POLLIN},2,7411)	 = 1 (0x1)
    19.094032811 select(5,{4},0x0,0x0,0x0)		 = 1 (0x1)
    19.103300869 recvmsg(0x4,0xbfbfe4d8,0x0,0x0,0x0,0xbfbfe454) = 128 (0x80)
    19.107260642 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    19.113427708 getpid()				 = 78607 (0x1330f)
    19.119468498 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: recvmsg len=128",49,0x0,NULL,0x0) = 49 (0x31)
    19.125577455 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    19.131655681 getpid()				 = 78607 (0x1330f)
    19.138024730 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: if_index 3",44,0x0,NULL,0x0) = 44 (0x2c)
    19.144222526 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    19.150330924 getpid()				 = 78607 (0x1330f)
    19.156578168 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: found Interface: bge1",55,0x0,NULL,0x0) = 55 (0x37)
    19.162705004 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    19.168790494 getpid()				 = 78607 (0x1330f)
    19.175264306 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: received RA from fe80::210:18ff:fe06:e4df",75,0x0,NULL,0x0) = 75 (0x4b)
    19.181473835 gettimeofday({1373710018.596061 },0x0) = 0 (0x0)
    19.187557369 gettimeofday({1373710018.602145 },0x0) = 0 (0x0)
    19.193656827 clock_gettime(13,{1373710018.000000000 }) = 0 (0x0)
    19.207662980 getpid()				 = 78607 (0x1330f)
    19.213864128 sendto(3,"<31>Jul 13 12:06:58 radvd[78607]: polling for 7.299 seconds.",60,0x0,NULL,0x0) = 60 (0x3c)
    26.527583639 poll({4/POLLIN 5/POLLIN},2,7299)	 = 0 (0x0)
    26.533836470 clock_gettime(13,{1373710025.000000000 }) = 0 (0x0)
    26.539983141 getpid()				 = 78607 (0x1330f)
    26.546323974 sendto(3,"<31>Jul 13 12:07:05 radvd[78607]: timer_handler called for bge1",63,0x0,NULL,0x0) = 63 (0x3f)
    26.552566189 ioctl(4,SIOCGIFFLAGS,0xbfbfdd40)	 = 0 (0x0)
    26.558731578 clock_gettime(13,{1373710025.000000000 }) = 0 (0x0)
    26.564700292 getpid()				 = 78607 (0x1330f)
    26.571192263 sendto(3,"<31>Jul 13 12:07:05 radvd[78607]: sending RA on bge1",52,0x0,NULL,0x0) = 52 (0x34)
    26.577279987 gettimeofday({1373710025.991867 },0x0) = 0 (0x0)
    26.583414645 gettimeofday({1373710025.998001 },0x0) = 0 (0x0)
    26.589581711 __sysctl(0xbfbfdd50,0x4,0xbfbfdd64,0xbfbfdd60,0x0,0x0) = 0 (0x0)
    26.595741792 clock_gettime(13,{1373710026.000000000 }) = 0 (0x0)
    26.601894609 getpid()				 = 78607 (0x1330f)
    26.608169790 sendto(3,"<31>Jul 13 12:07:06 radvd[78607]: adding prefix 2001:470:723c:20:: to advert for bge1",85,0x0,NULL,0x0) = 85 (0x55)
    26.614163088 clock_gettime(13,{1373710026.000000000 }) = 0 (0x0)
    26.620396643 getpid()				 = 78607 (0x1330f)
    26.626788041 sendto(3,"<31>Jul 13 12:07:06 radvd[78607]: using if_index 3 for interface bge1",69,0x0,NULL,0x0) = 69 (0x45)
    26.633118537 sendmsg(0x4,0xbfbfe3ec,0x0,0x3,0x28233100,0x1) ERR#13 'Permission denied'
    26.639469985 clock_gettime(13,{1373710026.000000000 }) = 0 (0x0)
    26.645668061 getpid()				 = 78607 (0x1330f)
    26.651997998 sendto(3,"<28>Jul 13 12:07:06 radvd[78607]: sendmsg: Permission denied",60,0x0,NULL,0x0) = 60 (0x3c)
    26.658165342 gettimeofday({1373710026.072751 },0x0) = 0 (0x0)
    26.664109192 gettimeofday({1373710026.078696 },0x0) = 0 (0x0)
    26.853962887 gettimeofday({1373710026.268550 },0x0) = 0 (0x0)
    26.859560598 clock_gettime(13,{1373710026.000000000 }) = 0 (0x0)
    26.863853937 getpid()				 = 78607 (0x1330f)
    26.869743869 sendto(3,"<31>Jul 13 12:07:06 radvd[78607]: polling for 15.805 seconds.",61,0x0,NULL,0x0) = 61 (0x3d)
    26.875744151 poll({4/POLLIN 5/POLLIN},2,15805)	 = 1 (0x1)
    26.881849196 select(5,{4},0x0,0x0,0x0)		 = 1 (0x1)
    26.887917085 recvmsg(0x4,0xbfbfe4d8,0x0,0x0,0x0,0x80) = 128 (0x80)
    26.894051464 clock_gettime(13,{1373710026.000000000 }) = 0 (0x0)
    26.900179697 getpid()				 = 78607 (0x1330f)
    26.906474713 sendto(3,"<31>Jul 13 12:07:06 radvd[78607]: recvmsg len=128",49,0x0,NULL,0x0) = 49 (0x31)
    26.912837337 clock_gettime(13,{1373710026.000000000 }) = 0 (0x0)
    26.919987501 getpid()				 = 78607 (0x1330f)
    26.924167416 sendto(3,"<31>Jul 13 12:07:06 radvd[78607]: if_index 3",44,0x0,NULL,0x0) = 44 (0x2c)
    26.927410608 clock_gettime(13,{1373710026.000000000 }) = 0 (0x0)
    26.931391612 getpid()				 = 78607 (0x1330f)
    26.934707161 sendto(3,"<31>Jul 13 12:07:06 radvd[78607]: found Interface: bge1",55,0x0,NULL,0x0) = 55 (0x37)
    26.938588990 clock_gettime(13,{1373710026.000000000 }) = 0 (0x0)
    26.941808714 getpid()				 = 78607 (0x1330f)
    26.945977734 sendto(3,"<31>Jul 13 12:07:06 radvd[78607]: received RA from fe80::210:18ff:fe06:e4df",75,0x0,NULL,0x0) = 75 (0x4b)
    26.950932618 gettimeofday({1373710026.365520 },0x0) = 0 (0x0)
    26.958284766 gettimeofday({1373710026.372872 },0x0) = 0 (0x0)
    26.967423476 clock_gettime(13,{1373710026.000000000 }) = 0 (0x0)
    26.975010852 getpid()				 = 78607 (0x1330f)
    26.980992137 sendto(3,"<31>Jul 13 12:07:06 radvd[78607]: polling for 15.7 seconds.",59,0x0,NULL,0x0) = 59 (0x3b)
    42.697526140 poll({4/POLLIN 5/POLLIN},2,15700)	 = 0 (0x0)
    42.703548212 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    42.710387718 getpid()				 = 78607 (0x1330f)
    42.716401130 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: timer_handler called for bge1",63,0x0,NULL,0x0) = 63 (0x3f)
    42.723529223 ioctl(4,SIOCGIFFLAGS,0xbfbfdd40)	 = 0 (0x0)
    42.729283940 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    42.736205579 getpid()				 = 78607 (0x1330f)
    42.742374321 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: sending RA on bge1",52,0x0,NULL,0x0) = 52 (0x34)
    42.749261039 gettimeofday({1373710042.163847 },0x0) = 0 (0x0)
    42.755037267 gettimeofday({1373710042.169624 },0x0) = 0 (0x0)
    42.762215647 __sysctl(0xbfbfdd50,0x4,0xbfbfdd64,0xbfbfdd60,0x0,0x0) = 0 (0x0)
    42.767903036 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    42.774668788 getpid()				 = 78607 (0x1330f)
    42.780863231 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: adding prefix 2001:470:723c:20:: to advert for bge1",85,0x0,NULL,0x0) = 85 (0x55)
    42.788050830 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    42.793773977 getpid()				 = 78607 (0x1330f)
    42.800902629 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: using if_index 3 for interface bge1",69,0x0,NULL,0x0) = 69 (0x45)
    42.806907381 sendmsg(0x4,0xbfbfe3ec,0x0,0x3,0x28233100,0x2) ERR#13 'Permission denied'
    42.821713645 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    42.827696605 getpid()				 = 78607 (0x1330f)
    42.834817435 sendto(3,"<28>Jul 13 12:07:22 radvd[78607]: sendmsg: Permission denied",60,0x0,NULL,0x0) = 60 (0x3c)
    42.840624394 gettimeofday({1373710042.255211 },0x0) = 0 (0x0)
    42.847726226 gettimeofday({1373710042.262313 },0x0) = 0 (0x0)
    42.853494911 gettimeofday({1373710042.268082 },0x0) = 0 (0x0)
    42.860525505 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    42.866436109 getpid()				 = 78607 (0x1330f)
    42.873686566 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: polling for 10.941 seconds.",61,0x0,NULL,0x0) = 61 (0x3d)
    42.879732944 poll({4/POLLIN 5/POLLIN},2,10941)	 = 1 (0x1)
    42.886806560 select(5,{4},0x0,0x0,0x0)		 = 1 (0x1)
    42.892969155 recvmsg(0x4,0xbfbfe4d8,0x0,0x0,0x0,0x80) = 128 (0x80)
    42.899998910 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    42.905718985 getpid()				 = 78607 (0x1330f)
    42.913277865 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: recvmsg len=128",49,0x0,NULL,0x0) = 49 (0x31)
    42.919110526 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    42.926108992 getpid()				 = 78607 (0x1330f)
    42.932304273 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: if_index 3",44,0x0,NULL,0x0) = 44 (0x2c)
    42.939376492 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    42.945564789 getpid()				 = 78607 (0x1330f)
    42.952916098 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: found Interface: bge1",55,0x0,NULL,0x0) = 55 (0x37)
    42.959049918 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    43.150465553 getpid()				 = 78607 (0x1330f)
    43.157522966 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: received RA from fe80::210:18ff:fe06:e4df",75,0x0,NULL,0x0) = 75 (0x4b)
    43.163210076 gettimeofday({1373710042.577795 },0x0) = 0 (0x0)
    43.168534565 gettimeofday({1373710042.583122 },0x0) = 0 (0x0)
    43.176349067 clock_gettime(13,{1373710042.000000000 }) = 0 (0x0)
    43.179460955 getpid()				 = 78607 (0x1330f)
    43.183598127 sendto(3,"<31>Jul 13 12:07:22 radvd[78607]: polling for 10.626 seconds.",61,0x0,NULL,0x0) = 61 (0x3d)
    53.817755167 poll({4/POLLIN 5/POLLIN},2,10626)	 = 0 (0x0)
    53.821776679 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    53.825027135 getpid()				 = 78607 (0x1330f)
    53.829214034 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: timer_handler called for bge1",63,0x0,NULL,0x0) = 63 (0x3f)
    53.834765090 ioctl(4,SIOCGIFFLAGS,0xbfbfdd40)	 = 0 (0x0)
    54.015158225 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.021632596 getpid()				 = 78607 (0x1330f)
    54.027333114 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: sending RA on bge1",52,0x0,NULL,0x0) = 52 (0x34)
    54.032197762 gettimeofday({1373710053.446785 },0x0) = 0 (0x0)
    54.038959044 gettimeofday({1373710053.453546 },0x0) = 0 (0x0)
    54.044090768 __sysctl(0xbfbfdd50,0x4,0xbfbfdd64,0xbfbfdd60,0x0,0x0) = 0 (0x0)
    54.050676048 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.056051102 getpid()				 = 78607 (0x1330f)
    54.063058787 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: adding prefix 2001:470:723c:20:: to advert for bge1",85,0x0,NULL,0x0) = 85 (0x55)
    54.068427416 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.075230882 getpid()				 = 78607 (0x1330f)
    54.080849267 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: using if_index 3 for interface bge1",69,0x0,NULL,0x0) = 69 (0x45)
    54.087952776 sendmsg(0x4,0xbfbfe3ec,0x0,0x3,0x28233100,0x2) ERR#13 'Permission denied'
    54.093400466 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.100293610 getpid()				 = 78607 (0x1330f)
    54.106009494 sendto(3,"<28>Jul 13 12:07:33 radvd[78607]: sendmsg: Permission denied",60,0x0,NULL,0x0) = 60 (0x3c)
    54.112837824 gettimeofday({1373710053.527425 },0x0) = 0 (0x0)
    54.118174884 gettimeofday({1373710053.532762 },0x0) = 0 (0x0)
    54.124905435 gettimeofday({1373710053.539493 },0x0) = 0 (0x0)
    54.130237467 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.137053226 getpid()				 = 78607 (0x1330f)
    54.142767713 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: polling for 8.976 seconds.",60,0x0,NULL,0x0) = 60 (0x3c)
    54.149446581 poll({4/POLLIN 5/POLLIN},2,8976)	 = 1 (0x1)
    54.154661557 select(5,{4},0x0,0x0,0x0)		 = 1 (0x1)
    54.161572022 recvmsg(0x4,0xbfbfe4d8,0x0,0x0,0x0,0x80) = 128 (0x80)
    54.167017477 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.173837706 getpid()				 = 78607 (0x1330f)
    54.179559457 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: recvmsg len=128",49,0x0,NULL,0x0) = 49 (0x31)
    54.186474950 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.191829890 getpid()				 = 78607 (0x1330f)
    54.198900433 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: if_index 3",44,0x0,NULL,0x0) = 44 (0x2c)
    54.204332478 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.211215286 getpid()				 = 78607 (0x1330f)
    54.224608781 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: found Interface: bge1",55,0x0,NULL,0x0) = 55 (0x37)
    54.231773751 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.237264743 getpid()				 = 78607 (0x1330f)
    54.244286955 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: received RA from fe80::210:18ff:fe06:e4df",75,0x0,NULL,0x0) = 75 (0x4b)
    54.249816780 gettimeofday({1373710053.664404 },0x0) = 0 (0x0)
    54.256777252 gettimeofday({1373710053.671364 },0x0) = 0 (0x0)
    54.262309032 clock_gettime(13,{1373710053.000000000 }) = 0 (0x0)
    54.269279282 getpid()				 = 78607 (0x1330f)
    54.274980359 sendto(3,"<31>Jul 13 12:07:33 radvd[78607]: polling for 8.844 seconds.",60,0x0,NULL,0x0) = 60 (0x3c)
    58.970540013 poll({4/POLLIN 5/POLLIN},2,8844)	 ERR#4 'Interrupted system call'
    58.970540013 SIGNAL 2 (SIGINT)
    58.976490287 sigaction(SIGINT,{ 0x804dda0 SA_RESTART ss_t },{ 0x804dda0 SA_RESTART ss_t }) = 0 (0x0)
    58.983569491 sigreturn(0xbfbfe200,0x2,0x10006,0xbfbfe200,0x0,0x804dda0) ERR#4 'Interrupted system call'
    58.989317223 clock_gettime(13,{1373710058.000000000 }) = 0 (0x0)
    58.996524377 getpid()				 = 78607 (0x1330f)
    59.002480798 sendto(3,"<30>Jul 13 12:07:38 radvd[78607]: poll returned early: Interrupted system call",78,0x0,NULL,0x0) = 78 (0x4e)
    59.010515722 clock_gettime(13,{1373710058.000000000 }) = 0 (0x0)
    59.014027107 getpid()				 = 78607 (0x1330f)
    59.018516562 sendto(3,"<28>Jul 13 12:07:38 radvd[78607]: Exiting, sigterm or sigint received.",70,0x0,NULL,0x0) = 70 (0x46)
    59.021833228 clock_gettime(13,{1373710058.000000000 }) = 0 (0x0)
    59.025937713 getpid()				 = 78607 (0x1330f)
    59.030846780 sendto(3,"<30>Jul 13 12:07:38 radvd[78607]: sending stop adverts",54,0x0,NULL,0x0) = 54 (0x36)
    59.033665890 ioctl(4,SIOCGIFFLAGS,0xbfbfe380)	 = 0 (0x0)
    59.038164006 clock_gettime(13,{1373710058.000000000 }) = 0 (0x0)
    59.045733501 getpid()				 = 78607 (0x1330f)
    59.052091375 sendto(3,"<31>Jul 13 12:07:38 radvd[78607]: sending RA on bge1",52,0x0,NULL,0x0) = 52 (0x34)
    59.059553592 gettimeofday({1373710058.474140 },0x0) = 0 (0x0)
    59.065758092 gettimeofday({1373710058.480345 },0x0) = 0 (0x0)
    59.072882553 clock_gettime(13,{1373710058.000000000 }) = 0 (0x0)
    59.079042354 getpid()				 = 78607 (0x1330f)
    59.086532509 sendto(3,"<31>Jul 13 12:07:38 radvd[78607]: adding prefix 2001:470:723c:20:: to advert for bge1",85,0x0,NULL,0x0) = 85 (0x55)
    59.092624423 clock_gettime(13,{1373710058.000000000 }) = 0 (0x0)
    59.099875439 getpid()				 = 78607 (0x1330f)
    59.106287789 sendto(3,"<31>Jul 13 12:07:38 radvd[78607]: using if_index 3 for interface bge1",69,0x0,NULL,0x0) = 69 (0x45)
    59.113847507 sendmsg(0x4,0xbfbfea2c,0x0,0x3,0x28233100,0x0) ERR#13 'Permission denied'
    59.120100058 clock_gettime(13,{1373710058.000000000 }) = 0 (0x0)
    59.127235135 getpid()				 = 78607 (0x1330f)
    59.133714254 sendto(3,"<28>Jul 13 12:07:38 radvd[78607]: sendmsg: Permission denied",60,0x0,NULL,0x0) = 60 (0x3c)
    59.308459110 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
    59.315405613 sigprocmask(SIG_SETMASK,0x0,0x0)	 = 0 (0x0)
    59.321158932 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
    59.328237577 sigprocmask(SIG_SETMASK,0x0,0x0)	 = 0 (0x0)
    59.335550891 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
    59.341727734 sigprocmask(SIG_SETMASK,0x0,0x0)	 = 0 (0x0)
    59.341727734 process exit, rval = 0
    
    

    After doing some research I think it's a bug in pfsense but I'm a little bit confused why I am the first who noticed it.  ???

    -Markus



  • Can you put the rule with advanced option to allow ip-options?
    Seems you are having fragments from the tunnel.


  • Banned

    1/ The MTU is configurable at the HE dashboard (http://www.tunnelbroker.net/ -> select your tunnel - Advanced - MTU)
    2/ As for your network setup, /96 is certainly NOT an advisable value to use for anything.
    3/ No matter what MTU I use, I'm getting fragmented packets blocked with some websites, sadly snapshots.pfsense.org being one of them, due to a clear FreeBSD bug which apparently got nowhere for years. I'm afraid "This allows packets with IP options to pass. Otherwise they are blocked by default. This is usually only seen with multicast traffic." is completely non-descriptive technical mumbo jumbo that noone will guess could help with similar issues, further confused by the multicast reference.



  • There is another guy today who has been running in circles all day trying to figure:

    1.  Why he has lots of IPV6 packets all over his network even though IPV6 is turned off in his pfsense.
    2.  He gets lots of herky jerky unriliable slow hit and miss on a network that used to work and randomly can't access these forums.

    Could this be the same issue?


  • Banned

    1/ In Windows world, IPv6 has been enabled and preferred by default protocol since Vista. You'll get LAN IPv6 traffic no matter whether tunnel is enabled or not. Further, Windows will attempt to use Teredo if no other IPv6 connectivity is available to get IPv6 working on internet as well.
    2/ Yes, absolutely what you see with the fragmented packets blocked issue. If you look at firewall logs, you'll recognize the problem very clearly by flood of FRAG log entries.

    P.S. https://redmine.pfsense.org/issues/2762



  • Cool….  I plan to present this info to the guy in question as if its my own research to make myself look smarter than I am and won't mention you at all.  (kidding).

    That problem has been a real pain to diagnose.  So?  Whats the fix?  Any?


  • Banned

    Try - where you have the IPv6 "catchall" allow rule enabled, edit -> Advanced Options - tick the checkbox with the above nondescriptive description (This allows packets with IP options to pass. Otherwise they are blocked by default. This is usually only seen with multicast traffic.) - Save - Apply. See if it helps.



  • And this IPV6 ICMP….

    http://imgur.com/1cgaMr5

    But IPV6 is off.


  • Banned

    546/547 is DHCPv6. It would go away if you enabled DHCPv6 Relay on the interface. Why is it blocked by default with the black magic in behind - no idea. For ICMP - this is all the local traffic. Allow ICMPv6 in floating rules, useless log noise gone. ICMPv6 is required for proper IPv6 working anyway.



  • OK.  I plagiarized you with cut and paste…  And am thinking of charging to worsen the crime.
    We will see how it goes.



  • well guys - that was not my main problem
    Nevertheles I changed the MTU on both sides of the tunnel to 1460. So I'm behind a DSL-line with a NAT-box. So I think the MTU on line is somewhat 1500 bytes. So there are 1500bytes - 6 bytes PPPoE - 2 bytes PPP-ID 20 bytes IPv4 header size - 0 bytes 6in4 = 1472 bytes. So 1460 bytes should be fine to work without fragmentation.

    But my problem is that the internal DHCPv6 server and the radvd seem not to work correctly. So some time after reboot it works for 10? minutes and then all stateful IPv6-adresses are gone. I changed the RA to assisted. So my clients get stateful and statless adresses - but after powersafe on my OSX notebook all IPv6 adresses are gone. I have a IPv6 capable printer. It keeps the stateless adress but forgets about the statful. Further I have a Synology-NAS. it never gets a stateful adress but a stateless.

    It seems to me that the DHCPv6-server in in combination with the radvd only work after reboot and then no RS and no RA are handled anymore.

    -Markus

    [EDIT] I never saw this issue: http://forum.pfsense.org/index.php/topic,59996.0.html


  • Banned

    As for Synology, it probably does not support DHCPv6 at all. QNAP for sure does not, tested here. I'd again like to point out that you should NOT use anything smaller than /64 for these purposes.



  • Sorry I forgot: I changed the subnet size to /64. It does not work either.

    -Markus



  • I tried to get some usable information about what goes wrong. I started a tcpdump on the client and on the internal if of pfsense. I saw router solicitation packets from the client on both dumps-but no answer. Dhcpd was up and running. So I killed dhcpd and started it from the command line in debug mode. Seeing the RS packets in tcpdump - nothing happened in dhcpd. So I switched off the firewall via Advanced->Network/Firewall.
    Now I see the RS packets, an reaction from dhcpd but no RA in dhcpd. So I think DHCPv6 Link local traffic seems o be blocked.
    So I think it's a bug in the definition of the internal rules because I have an any-any-pass rule on the firewall defined.
    Do you agree?

    -Markus


  • Banned

    @ermal:

    Can you put the rule with advanced option to allow ip-options?
    Seems you are having fragments from the tunnel.

    Well, except that you'd need the above done via "default accept" rule on WAN, which just defeats the whole purpose of the firewall… Setting this on any of the internal interfaces is useless, just tested myself. Still getting flood of blocked fragmented packets with this forum, and other pfsense.org sites.  :-X >:(

    No go without fixing the default rules.



  • You can override the default rules through the floating rules.
    First lets see if this works than lets fix the problem.

    So can you confirm that the issue is fixed by allowing fragments?


  • Banned

    Unfortunately no - since I cannot see how to create such rule in the first place without nuking firewall functionality. Floating rule for what? Creating the rule with allowopts on LAN has no effect as the traffic gets blocked on the tunnel WAN interface. I obviously do NOT want to create "allow any" IPv6 rules on WAN.



  • Finally I solved my problem.
    Disabeling the captive portal blocks dhcpv6.

    Background:
    I use a captive portal with freeradius2 auth and accounting (for the kids) with some VIP users (my wife). Because freeradius2 has a very long startup-time on my hardware the captive portal is disabled until freeradius2 is started. In this time it worked for me. Once freeradius2 is started the captive portal stops (almost) all dhcpv6 traffic.

    I think this is a bug on 2.1. Where to report?

    -Markus



  • CP + IPv6 is not in the 2.1 roadmap.
    For 2.2 probably yes.

    So we know about it but not for 2.1



  • I hope so.

    I wouldn't want my choices to be "IPV4 + features" or "IPV6 - features".



  • So I'd wish that CP was IPv6 aware. Even the CP doesn't support IPv6 enabeling it shouldn't break the DHCPv6 server.
    At least it is worth a note on the config page.
    -Markus


  • Banned

    @doktornotor:

    Unfortunately no - since I cannot see how to create such rule in the first place without nuking firewall functionality. Floating rule for what? Creating the rule with allowopts on LAN has no effect as the traffic gets blocked on the tunnel WAN interface. I obviously do NOT want to create "allow any" IPv6 rules on WAN.

    I'd really appreciate some ideas on how to prevent pf from dropping totally legit traffic…