const CONFLICT_OVERWRITE_PIM = 1;
/**
+ * Logger
+ *
+ * @var Horde_Log_Logger
+ */
+ protected $_logger;
+
+ /**
* Provisioning support
*
* @var string (TODO _constant this)
public function provisioningRequired()
{
+ $this->_logger->info('HTTP/1.1 449 Retry after sending a PROVISION command');
self::provisionHeader();
self::activeSyncHeader();
self::versionHeader();
}
/**
- * Read input from the php input stream
- *
- * @TODO: Get rid of this - the wbxml classes have a php:// stream already
- * and when we need *just* the stream and not wbxml, we can use
- * $request->body
- *
- * @return string
- */
- public function readStream()
- {
- $s = "";
- while (1) {
- $data = fread($this->_inputStream, 4096);
- if (strlen($data) == 0) {
- break;
- }
- $s .= $data;
- }
-
- return $s;
- }
-
- /**
* Send the MS_Server-ActiveSync header
* (This is the version Exchange 2003 implements)
*
*/
public function logon($username, $password, $domain = null)
{
- $this->_logger->debug('Horde_ActiveSync_Driver_Horde::logon');
+ $this->_logger->info('Horde_ActiveSync_Driver_Horde::logon attempt for: ' . $username);
parent::logon($username, $password, $domain);
-
- $this->_startProfiling();
$auth = Horde_Auth::singleton($GLOBALS['conf']['auth']['driver']);
return $auth->authenticate($username, array('password' => $password));
*/
public function Logoff()
{
- $this->_logger->debug('Horde_ActiveSync_Driver_Horde::logoff');
- $this->_endProfiling();
+ $this->_logger->info('Horde_ActiveSync_Driver_Horde::logoff');
return true;
}
*/
public function setup($user)
{
- $this->_logger->debug('Horde::Setup(' . $user . ')');
parent::setup($user);
$this->_modCache = array();
return true;
*/
public function StatMessage($folderid, $id)
{
- $this->_logger->debug('Horde::StatMessage(' . $folderid . ', ' . $id . ')');
return $this->_smartStatMessage($folderid, $id, true);
}
}
/**
- * Start profiling data
- *
- * @return void
- */
- private function _startProfiling()
- {
- $this->_starttime = microtime(true);
- }
-
- /**
- * End profiling
- *
- * @return void
- */
- private function _endProfiling()
- {
- $this->_logger->debug('Session lasted ' . sprintf('%0.3f',microtime(true) - $this->_starttime) . ' s');
- }
-
-
- /**
* Create a hash suitable for importing into contacts/import or
* contacts/replace from a Horde_ActiveSync_Message_Base object.
*
}
}
+ $this->_logger->debug('Policykey: ' . $sentKey . ' verified.');
+
return true;
}
{
$this->_version = $activeSync->getProtocolVersion();
$this->_devId = $devId;
+ $this->_logger->info('Request received from device: ' . $devId . ' Supporting protocol version: ' . $this->_version);
}
+ /**
+ * Read input from the php input stream
+ *
+ * @TODO: Get rid of this - the wbxml classes have a php:// stream already
+ * and when we need *just* the stream and not wbxml, we can use
+ * $request->body
+ *
+ * @return string
+ */
+ protected function _readStream()
+ {
+ $s = "";
+ while (1) {
+ $data = fread($this->_inputStream, 4096);
+ if (strlen($data) == 0) {
+ break;
+ }
+ $s .= $data;
+ }
+
+ return $s;
+ }
}
// FIXME
$timeout = 3;
- $this->_logger->info('Ping received for: ' . $this->_devId);
+ $this->_logger->info('[' . $devId . '] Ping received.');
/* Glass half full kinda guy... */
$this->_statusCode = self::STATUS_NOCHANGES;
/* Build the $collections array if we receive request from PIM */
if ($this->_decoder->getElementStartTag(SYNC_PING_PING)) {
- $this->_logger->debug('Ping init');
if ($this->_decoder->getElementStartTag(SYNC_PING_LIFETIME)) {
$lifetime = $this->_decoder->getElementContent();
$state->setPingLifetime($lifetime);
/* Start waiting for changes, but only if we don't have any errors */
if ($this->_statusCode == self::STATUS_NOCHANGES) {
- $this->_logger->info(sprintf('Waiting for changes... (lifetime %d)', $lifetime));
+ $this->_logger->info(sprintf('[%s] Waiting for changes (lifetime: %d)', $this->_devId, $lifetime));
// FIXME
//for ($n = 0; $n < $lifetime / $timeout; $n++) {
for ($n = 0; $n < 10; $n++) {
}
if ($dataavailable) {
- $this->_logger->info('Found changes');
+ $this->_logger->info('[' . $this->_devId . '] Changes available');
break;
}
sleep($timeout);
}
}
- $this->_logger->debug('Starting StartWBXML output');
+ $this->_logger->info('[' . $this->_devId . '] Sending response for PING.');
$this->_encoder->StartWBXML();
$this->_encoder->startTag(SYNC_PING_PING);
public function handle(Horde_ActiveSync $activeSync, $devId)
{
parent::handle($activeSync, $devId);
- $this->_logger->info('[Horde_ActiveSync::handleSync] Handling SYNC command.');
+ $this->_logger->info('[' . $this->_devId . '] Handling SYNC command.');
/* Check policy */
if (!$this->checkPolicyKey($activeSync->getPolicyKey())) {
}
$collection['class'] = $this->_decoder->getElementContent();
- $this->_logger->debug('[Horde_ActiveSync::handleSync] Folder class: ' . $collection['class']);
+ $this->_logger->info('[' . $this->_devId . '] Syncing folder class: ' . $collection['class']);
if (!$this->_decoder->getElementEndTag()) {
throw new Horde_ActiveSync_Exception('Protocol error');
}
if ($this->_decoder->getElementStartTag(SYNC_FOLDERID)) {
$collection['id'] = $this->_decoder->getElementContent();
- $this->_logger->debug('[Horde_ActiveSync::handleSync] Folder collectionid: ' . $collection['id']);
+ $this->_logger->info('[' . $this->_devId . '] Folder server id: ' . $collection['id']);
if (!$this->_decoder->getElementEndTag()) {
throw new Horde_ActiveSync_Exception('Protocol error');
}
}
}
- $this->_logger->debug(sprintf('[Horde_ActiveSync::handleSync] Processed %d incoming changes', $nchanges));
+ $this->_logger->debug(sprintf('[%s] Processed %d incoming changes', $this->_devId, $nchanges));
if (!$this->_decoder->getElementEndTag()) {
// end commands
}
/* Start output to PIM */
+ $this->_logger->info('[' . $this->_devId . '] Beginning SYNC Response.');
$this->_encoder->startWBXML();
$this->_encoder->startTag(SYNC_SYNCHRONIZE);
$this->_encoder->startTag(SYNC_FOLDERS);
$n++;
if (!empty($collection['windowsize']) && $n >= $collection['windowsize']) {
- $this->_logger->info(sprintf('[Horde_ActiveSync::handleSync] Exported maxItems of messages: %d - more available.', $collection['windowsize']));
+ $this->_logger->info(sprintf('[%s] Exported maxItems of messages: %d - more available.', $this->_devId, $collection['windowsize']));
break;
}
}
$state->setNewSyncKey($collection['newsynckey']);
$state->save();
} else {
- $this->_logger->err(sprintf('[Horde_ActiveSync::handleSync] Error saving %s - no state information available.', $collection["newsynckey"]));
+ $this->_logger->err(sprintf('[%s] Error saving %s - no state information available.', $this->_devId, $collection["newsynckey"]));
}
}
}
/* Initialize state for this collection */
if (!$haveState) {
- $this->_logger->debug('Empty state for '. $pingCollection['class']);
+ $this->_logger->info('[' . $this->_devId . '] Empty state for '. $pingCollection['class']);
/* Init members for the getChanges call */
$this->_syncKey = $this->_devId;
$state = serialize(array('lifetime' => $this->_pingState['lifetime'],
'collections' => $this->_pingState['collections']));
+ $this->_logger->info('[' . $this->_devId . '] Saving new PING state.');
return file_put_contents($this->_stateDir . '/' . $this->_backend->getUser() . '/' . $this->_devId, $state);
}
$info = $this->getDeviceInfo($devId);
$info->policykey = $key;
$this->setDeviceInfo($devId, $info);
+ $this->_logger->info('[' . $devId . '] New policykey saved: ' . $key);
}
/**
$info = $this->getDeviceInfo($devId);
$info->rwstatus = $status;
$this->setDeviceInfo($devId, $info);
+ $this->_logger->info('[' . $devId . '] Setting DeviceRWStatus: ' . $status);
}
/**
if (!empty($this->_collection['id'])) {
$folderId = $this->_collection['id'];
- $this->_logger->debug('Initializing message diff engine');
+ $this->_logger->info('[' . $this->_devId . '] Initializing message diff engine.');
if (!$syncState) {
$syncState = array();
}
- $this->_logger->debug(count($syncState) . ' messages in state');
+ $this->_logger->debug('[' . $this->_devId . ']' . count($syncState) . ' messages in state.');
- //do nothing if it is a dummy folder
+ /* do nothing if it is a dummy folder */
if ($folderId != SYNC_FOLDER_TYPE_DUMMY) {
// on ping: check if backend supports alternative PING mechanism & use it
if ($this->_collection['class'] === false && $flags == BACKEND_DISCARD_DATA && $this->_backend->AlterPing()) {
// Not even sure if we need this AlterPing?
$this->_changes = $this->_backend->AlterPingChanges($folderId, $syncState);
} else {
- // Get our lists - syncstate (old) and msglist (new)
+ /* Get our lists - syncstate (old) and msglist (new) */
$msglist = $this->_backend->GetMessageList($this->_collection['id'], $cutoffdate);
if ($msglist === false) {
return false;
$this->_changes = $this->_getDiff($syncState, $msglist);
}
}
- $this->_logger->debug('Found ' . count($this->_changes) . ' message changes');
+ $this->_logger->info('[' . $this->_devId . '] Found ' . count($this->_changes) . ' message changes.');
} else {
- $this->_logger->debug('Initializing folder diff engine');
+ $this->_logger->info('[' . $this->_devId . '] Initializing folder diff engine.');
$folderlist = $this->_backend->getFolderList();
if ($folderlist === false) {
return false;
}
$this->_changes = $this->_getDiff($syncState, $folderlist);
- $this->_logger->debug('Config: Found ' . count($this->_changes) . ' folder changes');
+ $this->_logger->info('[' . $this->_devId . '] Found ' . count($this->_changes) . ' folder changes.');
}
return $this->_changes;
$progress = array();
if ($this->_folderId == false) {
- //@TODO: Folder changes not implemented??
if ($this->_step < count($this->_changes)) {
$change = $this->_changes[$this->_step];