syncrepl not working in mode REFRESH_AND_PERSIST

Hello,

(OK, this is my code, so this is probably my fault, but it appears to
be above my knowledge.)

While trying to test REFRESH_AND_PERSIST mode:
- the intial results come (Search Entry with Sync State Control modify)
- then a Intermediate SyncInfo Message (with refreshDone=1)
- then nothing, even when changing entries in the LDAP.


Any idea?

As my explanation is probably insufficient, see the code below, the
attached output and http://www.ietf.org/rfc/rfc4533.txt

Mathieu Parent

=== CODE ===
#!/usr/bin/perl
#BEGIN {
#    push @INC, './perl-ldap/lib';
#}
use Data::Dumper;
use Net::LDAP;
use Net::LDAP::Control::SyncRequest;
use Net::LDAP::Constant qw(
LDAP_SYNC_REFRESH_ONLY
LDAP_SYNC_REFRESH_AND_PERSIST
LDAP_USER_CANCELED
LDAP_SUCCESS );

use warnings;
use strict;

$| = 1;

my $cookie = undef;
my $ldap = Net::LDAP->new( "ldap://192.168.0.15",
                            async    => 1,
                            onerror  => 'die',
                            #debug    => 15,
                            );
die $! if !$ldap;
my $req = Net::LDAP::Control::SyncRequest->new( mode =>
LDAP_SYNC_REFRESH_AND_PERSIST );
my $mesg2 = $ldap->search(base=> 'dc=local,dc=tld',
                            scope    => 'sub',
                            control  => [ $req ],
                            callback => \&searchCallback, # call for each entry
                            filter   => "(objectClass=*)",
                            attrs    => [ '*,+'],
                            );
while(!$mesg2->done()) {
    $ldap->process();
    sleep(1);
    print ".\n";
}

print "END\n";

sub searchCallback {
  print "<<Callback start\n";
   my $message = shift;
   my $param2 = shift; # might be entry or intermediate
   my @controls = $message->control;
  my @sync_controls;
  if($param2 && $param2->isa("Net::LDAP::Entry")) {
    print "Received Search Entry\n";
    #retrieve Sync State Control
    foreach my $ctrl (@controls) {
      push(@sync_controls, $ctrl)
        if $ctrl->isa('Net::LDAP::Control::SyncState');
    }
    die 'Got search entry with multiple Sync State controls' if
@sync_controls>1;
    die 'Got search entry without Sync State control' if !@sync_controls;
    die 'Got empty entryUUID' if !$sync_controls[0]->entryUUID;
    print 'Search Entry has Sync State Control: '.
      'state='.$sync_controls[0]->state().
      '; entryUUID='.unpack("H*",$sync_controls[0]->entryUUID()).
      '; cookie='.(defined($sync_controls[0]->cookie()) ?
$sync_controls[0]->cookie() : 'UNDEF')."\n";
    if(defined($sync_controls[0]->cookie)) {
      $cookie = $sync_controls[0]->cookie;
      print "New cookie: ".$cookie."\n";
    }
    print "Entry (".$param2->changetype."): ".$param2->dn()."\n";
  } elsif($param2 && $param2->isa("Net::LDAP::Reference")) {
    print "Received Search Reference\n";
    return;
  #if it not first control?
  } elsif($controls[0] and $controls[0]->isa('Net::LDAP::Control::SyncDone')) {
    print 'Received Sync Done Control: '.
      'cookie='.(defined($controls[0]->cookie()) ?
$controls[0]->cookie() : 'UNDEF').
      '; refreshDeletes='.$controls[0]->refreshDeletes()."\n";
    #we have a new cookie
    if(defined($controls[0]->cookie())
        and not $controls[0]->cookie() eq ''
        and not $controls[0]->cookie() eq $cookie) {
          $cookie = $controls[0]->cookie();
          print "New cookie: $cookie \n";
	  }
  } elsif($param2 && $param2->isa("Net::LDAP::Intermediate::SyncInfo")) {
    print "Received Intermediate SyncInfo Message\n";
    my $attrs = $param2->{asn};
    if($attrs->{newcookie}) {
      $cookie = $attrs->{newcookie};;
      print "New cookie: $cookie\n";
    } elsif(my $refreshInfos = ($attrs->{refreshDelete} ||
$attrs->{refreshPresent})) {
      $cookie = $refreshInfos->{cookie} if defined($refreshInfos->{cookie});
      print (defined($refreshInfos->{cookie}) ? 'New ' : 'Empty ');
      print "cookie from ".
        ($attrs->{refreshDelete} ? 'refreshDelete' : 'refreshPresent').
        " (refreshDone=".$refreshInfos->{refreshDone}."): $cookie\n";
    } elsif(my $syncIdSetInfos = $attrs->{syncIdSet}) {
      $cookie = $syncIdSetInfos->{cookie} if defined($syncIdSetInfos->{cookie});
      print (defined($syncIdSetInfos->{cookie}) ? 'Empty ' : 'New ');
      print "cookie from syncIdSet".
        " (refreshDeletes=".$syncIdSetInfos->{refreshDeletes}."): $cookie\n";
      foreach my $syncUUID ($syncIdSetInfos->{syncUUIDs}) {
        print 'entryUUID='.unpack("H*",$syncUUID)."\n";
      }
    }
  } elsif($message->code) {
    if ($message->code == 1) {
      die "Communication Error: disconnecting";
    } elsif ($message->code == LDAP_USER_CANCELED) {
        print "searchCallback() -> Exit code received, returning\n";
        return;
    } elsif ($message->code == 4096) {
        print "Refresh required\n";
        $cookie = '';
    } else {
        die "searchCallback: mesg->code = `" . $message->code . "',
mesg->msg = `" . $message->error . "'";
    }
  } else {
    die "Received something else.";
  }
  print "Callback end>>\n";
  return 0;
 }

<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=e71d07fa7091102e9ff775452365ae8f; cookie=UNDEF
Entry (modify): dc=local,dc=tld
Callback end>>
<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=e739c1567091102e9ffb75452365ae8f; cookie=UNDEF
Entry (modify): cn=external,dc=local,dc=tld
Callback end>>
<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=e73b60247091102e9ffc75452365ae8f; cookie=UNDEF
Entry (modify): cn=groups,dc=local,dc=tld
Callback end>>
<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=e73caf247091102e9ffd75452365ae8f; cookie=UNDEF
Entry (modify): cn=resources,dc=local,dc=tld
Callback end>>
<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=76ea76f67092102e96a64166169ab143; cookie=UNDEF
Entry (modify): cn=Mathieu Parent,dc=local,dc=tld
Callback end>>
<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=8be4a3fe7094102e96a74166169ab143; cookie=UNDEF
Entry (modify): [email protected],dc=local,dc=tld
Callback end>>
<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=8bec9b7c7094102e96a84166169ab143; cookie=UNDEF
Entry (modify): [email protected],dc=local,dc=tld
Callback end>>
<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=8befaca47094102e96a94166169ab143; cookie=UNDEF
Entry (modify): [email protected],dc=local,dc=tld
Callback end>>
<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=8bf21fc07094102e96aa4166169ab143; cookie=UNDEF
Entry (modify): [email protected],dc=local,dc=tld
Callback end>>
<<Callback start
Received Search Entry
Search Entry has Sync State Control: state=1; entryUUID=8bf4c96e7094102e96ab4166169ab143; cookie=UNDEF
Entry (modify): [email protected],dc=local,dc=tld
Callback end>>
<<Callback start
Received Intermediate SyncInfo Message
New cookie from refreshDelete (refreshDone=1): rid=000,sid=000,csn=20091203204334.412000Z#000000#000#000000
Callback end>>
.