repl5_inc_protocol.c 88 KB

1234567891011121314151617181920212223242526272829303132333435363738394041424344454647484950515253545556575859606162636465666768697071727374757677787980818283848586878889909192939495969798991001011021031041051061071081091101111121131141151161171181191201211221231241251261271281291301311321331341351361371381391401411421431441451461471481491501511521531541551561571581591601611621631641651661671681691701711721731741751761771781791801811821831841851861871881891901911921931941951961971981992002012022032042052062072082092102112122132142152162172182192202212222232242252262272282292302312322332342352362372382392402412422432442452462472482492502512522532542552562572582592602612622632642652662672682692702712722732742752762772782792802812822832842852862872882892902912922932942952962972982993003013023033043053063073083093103113123133143153163173183193203213223233243253263273283293303313323333343353363373383393403413423433443453463473483493503513523533543553563573583593603613623633643653663673683693703713723733743753763773783793803813823833843853863873883893903913923933943953963973983994004014024034044054064074084094104114124134144154164174184194204214224234244254264274284294304314324334344354364374384394404414424434444454464474484494504514524534544554564574584594604614624634644654664674684694704714724734744754764774784794804814824834844854864874884894904914924934944954964974984995005015025035045055065075085095105115125135145155165175185195205215225235245255265275285295305315325335345355365375385395405415425435445455465475485495505515525535545555565575585595605615625635645655665675685695705715725735745755765775785795805815825835845855865875885895905915925935945955965975985996006016026036046056066076086096106116126136146156166176186196206216226236246256266276286296306316326336346356366376386396406416426436446456466476486496506516526536546556566576586596606616626636646656666676686696706716726736746756766776786796806816826836846856866876886896906916926936946956966976986997007017027037047057067077087097107117127137147157167177187197207217227237247257267277287297307317327337347357367377387397407417427437447457467477487497507517527537547557567577587597607617627637647657667677687697707717727737747757767777787797807817827837847857867877887897907917927937947957967977987998008018028038048058068078088098108118128138148158168178188198208218228238248258268278288298308318328338348358368378388398408418428438448458468478488498508518528538548558568578588598608618628638648658668678688698708718728738748758768778788798808818828838848858868878888898908918928938948958968978988999009019029039049059069079089099109119129139149159169179189199209219229239249259269279289299309319329339349359369379389399409419429439449459469479489499509519529539549559569579589599609619629639649659669679689699709719729739749759769779789799809819829839849859869879889899909919929939949959969979989991000100110021003100410051006100710081009101010111012101310141015101610171018101910201021102210231024102510261027102810291030103110321033103410351036103710381039104010411042104310441045104610471048104910501051105210531054105510561057105810591060106110621063106410651066106710681069107010711072107310741075107610771078107910801081108210831084108510861087108810891090109110921093109410951096109710981099110011011102110311041105110611071108110911101111111211131114111511161117111811191120112111221123112411251126112711281129113011311132113311341135113611371138113911401141114211431144114511461147114811491150115111521153115411551156115711581159116011611162116311641165116611671168116911701171117211731174117511761177117811791180118111821183118411851186118711881189119011911192119311941195119611971198119912001201120212031204120512061207120812091210121112121213121412151216121712181219122012211222122312241225122612271228122912301231123212331234123512361237123812391240124112421243124412451246124712481249125012511252125312541255125612571258125912601261126212631264126512661267126812691270127112721273127412751276127712781279128012811282128312841285128612871288128912901291129212931294129512961297129812991300130113021303130413051306130713081309131013111312131313141315131613171318131913201321132213231324132513261327132813291330133113321333133413351336133713381339134013411342134313441345134613471348134913501351135213531354135513561357135813591360136113621363136413651366136713681369137013711372137313741375137613771378137913801381138213831384138513861387138813891390139113921393139413951396139713981399140014011402140314041405140614071408140914101411141214131414141514161417141814191420142114221423142414251426142714281429143014311432143314341435143614371438143914401441144214431444144514461447144814491450145114521453145414551456145714581459146014611462146314641465146614671468146914701471147214731474147514761477147814791480148114821483148414851486148714881489149014911492149314941495149614971498149915001501150215031504150515061507150815091510151115121513151415151516151715181519152015211522152315241525152615271528152915301531153215331534153515361537153815391540154115421543154415451546154715481549155015511552155315541555155615571558155915601561156215631564156515661567156815691570157115721573157415751576157715781579158015811582158315841585158615871588158915901591159215931594159515961597159815991600160116021603160416051606160716081609161016111612161316141615161616171618161916201621162216231624162516261627162816291630163116321633163416351636163716381639164016411642164316441645164616471648164916501651165216531654165516561657165816591660166116621663166416651666166716681669167016711672167316741675167616771678167916801681168216831684168516861687168816891690169116921693169416951696169716981699170017011702170317041705170617071708170917101711171217131714171517161717171817191720172117221723172417251726172717281729173017311732173317341735173617371738173917401741174217431744174517461747174817491750175117521753175417551756175717581759176017611762176317641765176617671768176917701771177217731774177517761777177817791780178117821783178417851786178717881789179017911792179317941795179617971798179918001801180218031804180518061807180818091810181118121813181418151816181718181819182018211822182318241825182618271828182918301831183218331834183518361837183818391840184118421843184418451846184718481849185018511852185318541855185618571858185918601861186218631864186518661867186818691870187118721873187418751876187718781879188018811882188318841885188618871888188918901891189218931894189518961897189818991900190119021903190419051906190719081909191019111912191319141915191619171918191919201921192219231924192519261927192819291930193119321933193419351936193719381939194019411942194319441945194619471948194919501951195219531954195519561957195819591960196119621963196419651966196719681969197019711972197319741975197619771978197919801981198219831984198519861987198819891990199119921993199419951996199719981999200020012002200320042005200620072008200920102011201220132014201520162017201820192020202120222023202420252026202720282029203020312032203320342035203620372038203920402041204220432044204520462047204820492050205120522053205420552056205720582059206020612062206320642065206620672068206920702071207220732074207520762077207820792080208120822083208420852086208720882089209020912092209320942095209620972098209921002101210221032104210521062107210821092110211121122113211421152116211721182119212021212122212321242125212621272128212921302131213221332134213521362137213821392140214121422143214421452146214721482149215021512152215321542155215621572158215921602161216221632164216521662167216821692170217121722173217421752176217721782179218021812182218321842185218621872188218921902191219221932194219521962197219821992200220122022203220422052206220722082209221022112212221322142215221622172218221922202221222222232224222522262227222822292230223122322233223422352236223722382239224022412242224322442245224622472248224922502251225222532254225522562257225822592260226122622263226422652266226722682269227022712272227322742275227622772278227922802281228222832284228522862287228822892290229122922293229422952296229722982299230023012302230323042305230623072308230923102311231223132314231523162317231823192320232123222323232423252326232723282329233023312332233323342335233623372338233923402341234223432344234523462347234823492350235123522353235423552356235723582359236023612362236323642365236623672368236923702371237223732374237523762377237823792380238123822383238423852386238723882389239023912392239323942395239623972398239924002401240224032404240524062407240824092410241124122413241424152416241724182419242024212422242324242425242624272428242924302431243224332434243524362437243824392440
  1. /** BEGIN COPYRIGHT BLOCK
  2. * This Program is free software; you can redistribute it and/or modify it under
  3. * the terms of the GNU General Public License as published by the Free Software
  4. * Foundation; version 2 of the License.
  5. *
  6. * This Program is distributed in the hope that it will be useful, but WITHOUT
  7. * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
  8. * FOR A PARTICULAR PURPOSE. See the GNU General Public License for more details.
  9. *
  10. * You should have received a copy of the GNU General Public License along with
  11. * this Program; if not, write to the Free Software Foundation, Inc., 59 Temple
  12. * Place, Suite 330, Boston, MA 02111-1307 USA.
  13. *
  14. * In addition, as a special exception, Red Hat, Inc. gives You the additional
  15. * right to link the code of this Program with code not covered under the GNU
  16. * General Public License ("Non-GPL Code") and to distribute linked combinations
  17. * including the two, subject to the limitations in this paragraph. Non-GPL Code
  18. * permitted under this exception must only link to the code of this Program
  19. * through those well defined interfaces identified in the file named EXCEPTION
  20. * found in the source code files (the "Approved Interfaces"). The files of
  21. * Non-GPL Code may instantiate templates or use macros or inline functions from
  22. * the Approved Interfaces without causing the resulting work to be covered by
  23. * the GNU General Public License. Only Red Hat, Inc. may make changes or
  24. * additions to the list of Approved Interfaces. You must obey the GNU General
  25. * Public License in all respects for all of the Program code and other code used
  26. * in conjunction with the Program except the Non-GPL Code covered by this
  27. * exception. If you modify this file, you may extend this exception to your
  28. * version of the file, but you are not obligated to do so. If you do not wish to
  29. * provide this exception without modification, you must delete this exception
  30. * statement from your version and license this file solely under the GPL without
  31. * exception.
  32. *
  33. *
  34. * Copyright (C) 2001 Sun Microsystems, Inc. Used by permission.
  35. * Copyright (C) 2005 Red Hat, Inc.
  36. * All rights reserved.
  37. * END COPYRIGHT BLOCK **/
  38. #ifdef HAVE_CONFIG_H
  39. # include <config.h>
  40. #endif
  41. /* repl5_inc_protocol.c */
  42. /*
  43. The Prot_Incremental object implements the DS 5.0 multi-master incremental
  44. replication protocol.
  45. Stuff to do:
  46. - Need to figure out how asynchronous events end up in here. They are:
  47. - entry updated in replicated area.
  48. - backoff timeout
  49. - enter/leave.
  50. Perhaps these events should be properties of the main protocol.
  51. */
  52. #include <plstr.h>
  53. #include "repl.h"
  54. #include "repl5.h"
  55. #include "repl5_ruv.h"
  56. #include "repl5_prot_private.h"
  57. #include "cl5_api.h"
  58. #include "repl5.h"
  59. #include "repl5_prot_private.h"
  60. #include "cl5_api.h"
  61. #include "slapi-plugin.h"
  62. extern int slapi_log_urp;
  63. /*** from proto-slap.h ***/
  64. void ava_done(struct ava *ava);
  65. typedef struct repl5_inc_private
  66. {
  67. char *ruv; /* RUV on remote replica (use diff type for this? - ggood */
  68. Backoff_Timer *backoff;
  69. Repl_Protocol *rp;
  70. PRLock *lock;
  71. PRUint32 eventbits;
  72. } repl5_inc_private;
  73. /* Structures used to communicate with the result reading thread */
  74. #ifndef UIDSTR_SIZE
  75. #define UIDSTR_SIZE 35 /* size of the string representation of the id */
  76. #endif
  77. typedef struct repl5_inc_operation
  78. {
  79. int ldap_message_id;
  80. unsigned long operation_type;
  81. char csn_str[CSN_STRSIZE];
  82. char uniqueid[UIDSTR_SIZE+1];
  83. ReplicaId replica_id;
  84. struct repl5_inc_operation *next;
  85. } repl5_inc_operation;
  86. typedef struct result_data
  87. {
  88. Private_Repl_Protocol *prp;
  89. int rc;
  90. PRLock *lock; /* Lock to protect access to this structure, the message id list and to force memory barriers */
  91. PRThread *result_tid; /* The async result thread */
  92. repl5_inc_operation *operation_list_head; /* List of IDs for outstanding operations */
  93. repl5_inc_operation *operation_list_tail; /* List of IDs for outstanding operations */
  94. int abort; /* Flag used to tell the sending thread asyncronously that it should abort (because an error came up in a result) */
  95. PRUint32 num_changes_sent;
  96. int stop_result_thread; /* Flag used to tell the result thread to exit */
  97. int last_message_id_sent;
  98. int last_message_id_received;
  99. int flowcontrol_detection;
  100. int result; /* The UPDATE_TRANSIENT_ERROR etc */
  101. time_t abort_time;
  102. } result_data;
  103. /* Various states the incremental protocol can pass through */
  104. #define STATE_START 0 /* ONREPL - should we rename this - we don't use it just to start up? */
  105. #define STATE_WAIT_WINDOW_OPEN 1
  106. #define STATE_WAIT_CHANGES 2
  107. #define STATE_READY_TO_ACQUIRE 3
  108. #define STATE_BACKOFF_START 4 /* ONREPL - can we combine BACKOFF_START and BACKOFF states? */
  109. #define STATE_BACKOFF 5
  110. #define STATE_SENDING_UPDATES 6
  111. #define STATE_STOP_FATAL_ERROR 7
  112. #define STATE_STOP_FATAL_ERROR_PART2 8
  113. #define STATE_STOP_NORMAL_TERMINATION 9
  114. /* Events (synchronous and asynchronous; these are bits) */
  115. #define EVENT_WINDOW_OPENED 1
  116. #define EVENT_WINDOW_CLOSED 2
  117. #define EVENT_TRIGGERING_CRITERIA_MET 4 /* ONREPL - should we rename this to EVENT_CHANGE_AVAILABLE */
  118. #define EVENT_BACKOFF_EXPIRED 8
  119. #define EVENT_REPLICATE_NOW 16
  120. #define EVENT_PROTOCOL_SHUTDOWN 32
  121. #define EVENT_AGMT_CHANGED 64
  122. #define UPDATE_NO_MORE_UPDATES 201
  123. #define UPDATE_TRANSIENT_ERROR 202
  124. #define UPDATE_FATAL_ERROR 203
  125. #define UPDATE_SCHEDULE_WINDOW_CLOSED 204
  126. #define UPDATE_CONNECTION_LOST 205
  127. #define UPDATE_TIMEOUT 206
  128. #define UPDATE_YIELD 207
  129. /* Return codes from examine_update_vector */
  130. #define EXAMINE_RUV_PRISTINE_REPLICA 401
  131. #define EXAMINE_RUV_GENERATION_MISMATCH 402
  132. #define EXAMINE_RUV_REPLICA_TOO_OLD 403
  133. #define EXAMINE_RUV_OK 404
  134. #define EXAMINE_RUV_PARAM_ERROR 405
  135. #define MAX_CHANGES_PER_SESSION 10000
  136. /*
  137. * Maximum time to wait between replication sessions. If we
  138. * don't see any updates for a period equal to this interval,
  139. * we go ahead and start a replication session, just to be safe
  140. */
  141. #define MAX_WAIT_BETWEEN_SESSIONS PR_SecondsToInterval(60 * 5) /* 5 minutes */
  142. /*
  143. * tests if the protocol has been shutdown and we need to quit
  144. * event_occurred resets the bits in the bit flag, so whoever tests for shutdown
  145. * resets the flags, so the next one who tests for shutdown won't get it, so we
  146. * also look at the terminate flag
  147. */
  148. #define PROTOCOL_IS_SHUTDOWN(prp) (event_occurred(prp, EVENT_PROTOCOL_SHUTDOWN) || prp->terminate)
  149. /* mods should be LDAPMod **mods */
  150. #define MODS_ARE_EMPTY(mods) ((mods == NULL) || (mods[0] == NULL))
  151. /* Forward declarations */
  152. static PRUint32 event_occurred(Private_Repl_Protocol *prp, PRUint32 event);
  153. static void reset_events (Private_Repl_Protocol *prp);
  154. static void protocol_sleep(Private_Repl_Protocol *prp, PRIntervalTime duration);
  155. static int send_updates(Private_Repl_Protocol *prp, RUV *ruv, PRUint32 *num_changes_sent);
  156. static void repl5_inc_backoff_expired(time_t timer_fire_time, void *arg);
  157. static int examine_update_vector(Private_Repl_Protocol *prp, RUV *ruv);
  158. static const char* state2name (int state);
  159. static const char* event2name (int event);
  160. static const char* op2string (int op);
  161. static int repl5_inc_update_from_op_result(Private_Repl_Protocol *prp, ConnResult replay_crc, int connection_error, char *csn_str, char *uniqueid, ReplicaId replica_id, int* finished, PRUint32 *num_changes_sent);
  162. /* Push a newly sent operation onto the tail of the list */
  163. static void repl5_int_push_operation(result_data *rd, repl5_inc_operation *it)
  164. {
  165. repl5_inc_operation *tail = NULL;
  166. PR_Lock(rd->lock);
  167. tail = rd->operation_list_tail;
  168. if (tail)
  169. {
  170. tail->next = it;
  171. }
  172. if (NULL == rd->operation_list_head)
  173. {
  174. rd->operation_list_head = it;
  175. }
  176. rd->operation_list_tail = it;
  177. PR_Unlock(rd->lock);
  178. }
  179. /* Pop the next operation in line to respond from the list */
  180. /* The caller is expected to free the operation item */
  181. static repl5_inc_operation *repl5_inc_pop_operation(result_data *rd)
  182. {
  183. repl5_inc_operation *head = NULL;
  184. repl5_inc_operation *ret = NULL;
  185. PR_Lock(rd->lock);
  186. head = rd->operation_list_head;
  187. if (head)
  188. {
  189. ret = head;
  190. rd->operation_list_head = head->next;
  191. if (rd->operation_list_tail == head)
  192. {
  193. rd->operation_list_tail = NULL;
  194. }
  195. }
  196. PR_Unlock(rd->lock);
  197. return ret;
  198. }
  199. static void
  200. repl5_inc_op_free(repl5_inc_operation *op)
  201. {
  202. slapi_ch_free((void**)&op);
  203. }
  204. static repl5_inc_operation *repl5_inc_operation_new()
  205. {
  206. repl5_inc_operation *ret = NULL;
  207. ret = (repl5_inc_operation *) slapi_ch_calloc(1,sizeof(repl5_inc_operation));
  208. return ret;
  209. }
  210. /* Called when in compatibility mode, to get the next result from the wire
  211. * The operation thread will not send a second operation until it has read the
  212. * previous result. */
  213. static int
  214. repl5_inc_get_next_result(result_data *rd)
  215. {
  216. ConnResult conres = 0;
  217. int message_id = 0;
  218. /* Wait on the next result */
  219. conres = conn_read_result(rd->prp->conn, &message_id);
  220. /* Return it to the caller */
  221. return conres;
  222. }
  223. #if NEEDED_FOR_DEBUGGING
  224. static void
  225. repl5_inc_log_operation_failure(int operation_code, int ldap_error, char* ldap_error_string, const char *agreement_name)
  226. {
  227. char *op_string = slapi_op_type_to_string(operation_code);
  228. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  229. "%s: Received error %d: %s for %s operation\n",
  230. agreement_name,
  231. ldap_error, ldap_error_string ? ldap_error_string : "NULL",
  232. op_string ? op_string : "NULL");
  233. }
  234. #endif
  235. /* Thread that collects results from async operations sent to the consumer */
  236. static void repl5_inc_result_threadmain(void *param)
  237. {
  238. result_data *rd = (result_data*) param;
  239. ConnResult conres = 0;
  240. Repl_Connection *conn = rd->prp->conn;
  241. int finished = 0;
  242. int message_id = 0;
  243. int yield_session = 0;
  244. slapi_log_error(SLAPI_LOG_REPL, NULL, "repl5_inc_result_threadmain starting\n");
  245. while (!finished)
  246. {
  247. LDAPControl **returned_controls = NULL;
  248. repl5_inc_operation *op = NULL;
  249. ReplicaId replica_id = 0;
  250. char *csn_str = NULL;
  251. char *uniqueid = NULL;
  252. char *ldap_error_string = NULL;
  253. time_t time_now = 0;
  254. time_t start_time = time( NULL );
  255. int connection_error = 0;
  256. int operation_code = 0;
  257. int backoff_time = 1;
  258. /* Read the next result */
  259. /* We call the get result function with a short timeout (non-blocking)
  260. * this is so we don't block here forever, and can stop this thread when
  261. * the time comes. However, we do need to implement blocking with timeout
  262. * semantics here instead.
  263. */
  264. while (!finished)
  265. {
  266. conres = conn_read_result_ex(conn, NULL, NULL, &returned_controls, LDAP_RES_ANY, &message_id, 0);
  267. slapi_log_error(SLAPI_LOG_REPL, NULL, "repl5_inc_result_threadmain: read result for message_id %d\n", message_id);
  268. /* Timeout here means that we didn't block, not a real timeout */
  269. if (CONN_TIMEOUT == conres)
  270. {
  271. /* We need to a) check that the 'real' timeout hasn't expired and
  272. * b) implement a backoff sleep to avoid spinning */
  273. /* Did the connection's timeout expire ? */
  274. time_now = time( NULL );
  275. if (conn_get_timeout(conn) <= ( time_now - start_time ))
  276. {
  277. /* We timed out */
  278. conres = CONN_TIMEOUT;
  279. break;
  280. }
  281. /* Otherwise we backoff */
  282. DS_Sleep(PR_MillisecondsToInterval(backoff_time));
  283. if (backoff_time < 1000)
  284. {
  285. backoff_time <<= 1;
  286. }
  287. /* Should we stop ? */
  288. PR_Lock(rd->lock);
  289. if (rd->stop_result_thread)
  290. {
  291. finished = 1;
  292. }
  293. PR_Unlock(rd->lock);
  294. } else {
  295. /*
  296. * Something other than a timeout, so we exit the loop.
  297. * First check if we were told to abort the session
  298. */;
  299. Replica *r = (Replica*)object_get_data(rd->prp->replica_object);
  300. if (replica_get_release_timeout(r) &&
  301. slapi_control_present(returned_controls,
  302. REPL_ABORT_SESSION_OID,
  303. NULL, NULL))
  304. {
  305. yield_session = 1;
  306. }
  307. break;
  308. }
  309. }
  310. if (conres != CONN_TIMEOUT)
  311. {
  312. int return_value;
  313. int should_finish = 0;
  314. if (message_id)
  315. {
  316. rd->last_message_id_received = message_id;
  317. }
  318. /* Handle any error etc */
  319. /* Get the stored operation details from the queue, unless we timed out... */
  320. op = repl5_inc_pop_operation(rd);
  321. if (op)
  322. {
  323. csn_str = op->csn_str;
  324. replica_id = op->replica_id;
  325. uniqueid = op->uniqueid;
  326. }
  327. conn_get_error_ex(conn, &operation_code, &connection_error, &ldap_error_string);
  328. slapi_log_error(SLAPI_LOG_REPL, NULL,
  329. "repl5_inc_result_threadmain: result %d, %d, %d, %d, %s\n",
  330. operation_code,connection_error,conres,message_id,ldap_error_string);
  331. return_value = repl5_inc_update_from_op_result(rd->prp, conres, connection_error,
  332. csn_str, uniqueid, replica_id, &should_finish,
  333. &(rd->num_changes_sent));
  334. if (return_value || should_finish)
  335. {
  336. slapi_log_error(SLAPI_LOG_REPL, NULL,
  337. "repl5_inc_result_threadmain: got op result %d should finish %d\n",
  338. return_value, should_finish);
  339. /* If so then we need to take steps to abort the update process */
  340. PR_Lock(rd->lock);
  341. rd->result = return_value;
  342. rd->abort = ABORT_SESSION;
  343. PR_Unlock(rd->lock);
  344. /*
  345. * We also need to log the error, including details stored from
  346. * when the operation was sent. We cannot finish yet - we still
  347. * need to wait for the pending results, then the main repl code
  348. * will shut down this thread. We can finish if we have
  349. * disconnected - in that case, there will be nothing to read
  350. */
  351. if (return_value == UPDATE_CONNECTION_LOST) {
  352. finished = 1;
  353. }
  354. } else {
  355. /* old semantics had result set outside of lock */
  356. rd->result = return_value;
  357. }
  358. }
  359. /* Should we stop ? */
  360. PR_Lock(rd->lock);
  361. if (!finished && yield_session && rd->abort != SESSION_ABORTED && rd->abort_time == 0) {
  362. rd->abort_time = time( NULL );
  363. rd->abort = SESSION_ABORTED; /* only set the abort time once */
  364. slapi_log_error(SLAPI_LOG_REPL, "repl5_inc_result_threadmain",
  365. "Abort control detected, setting abort time...(%s)\n",
  366. agmt_get_long_name(rd->prp->agmt));
  367. }
  368. if (rd->stop_result_thread)
  369. {
  370. finished = 1;
  371. }
  372. PR_Unlock(rd->lock);
  373. if (op)
  374. {
  375. repl5_inc_op_free(op);
  376. }
  377. }
  378. slapi_log_error(SLAPI_LOG_REPL, NULL, "repl5_inc_result_threadmain exiting\n");
  379. }
  380. static result_data *
  381. repl5_inc_rd_new(Private_Repl_Protocol *prp)
  382. {
  383. result_data *res = NULL;
  384. res = (result_data *) slapi_ch_calloc(1,sizeof(result_data));
  385. if (res) {
  386. res->prp = prp;
  387. res->lock = PR_NewLock();
  388. if (NULL == res->lock) {
  389. slapi_ch_free((void **)&res);
  390. res = NULL;
  391. }
  392. }
  393. return res;
  394. }
  395. static void
  396. repl5_inc_rd_list_destroy(repl5_inc_operation *op)
  397. {
  398. while (op) {
  399. repl5_inc_operation *next = op->next;
  400. repl5_inc_op_free(op);
  401. op = next;
  402. }
  403. }
  404. static void
  405. repl5_inc_rd_destroy(result_data **pres)
  406. {
  407. result_data *res = *pres;
  408. if (res->lock) {
  409. PR_DestroyLock(res->lock);
  410. }
  411. /* Delete the linked list if we have one */
  412. /* Begin at the head */
  413. repl5_inc_rd_list_destroy(res->operation_list_head);
  414. slapi_ch_free((void **)pres);
  415. }
  416. static int
  417. repl5_inc_create_async_result_thread(result_data *rd)
  418. {
  419. int retval = 0;
  420. PRThread *tid = NULL;
  421. /* Create a thread that reads results from the connection and stores status in the callback_data structure */
  422. tid = PR_CreateThread(PR_USER_THREAD,
  423. repl5_inc_result_threadmain, (void*)rd,
  424. PR_PRIORITY_NORMAL, PR_GLOBAL_THREAD, PR_JOINABLE_THREAD,
  425. SLAPD_DEFAULT_THREAD_STACKSIZE);
  426. if (NULL == tid)
  427. {
  428. slapi_log_error(SLAPI_LOG_FATAL, NULL,
  429. "repl5_tot_create_async_result_thread failed. "
  430. SLAPI_COMPONENT_NAME_NSPR " error %d (%s)\n",
  431. PR_GetError(), slapd_pr_strerror( PR_GetError() ));
  432. retval = -1;
  433. } else {
  434. rd->result_tid = tid;
  435. }
  436. return retval;
  437. }
  438. static int
  439. repl5_inc_destroy_async_result_thread(result_data *rd)
  440. {
  441. int retval = 0;
  442. PRThread *tid = rd->result_tid;
  443. if (tid) {
  444. PR_Lock(rd->lock);
  445. rd->stop_result_thread = 1;
  446. PR_Unlock(rd->lock);
  447. (void)PR_JoinThread(tid);
  448. }
  449. return retval;
  450. }
  451. /* The interest of this routine is to give time to the consumer
  452. * to apply the sent updates and return the acks.
  453. * So the caller should not hold the replication connection lock
  454. * to let the RA.reader receives the acks.
  455. */
  456. static void
  457. repl5_inc_flow_control_results(Repl_Agmt *agmt, result_data *rd)
  458. {
  459. PR_Lock(rd->lock);
  460. if ((rd->last_message_id_received <= rd->last_message_id_sent) &&
  461. ((rd->last_message_id_sent - rd->last_message_id_received) >= agmt_get_flowcontrolwindow(agmt))) {
  462. rd->flowcontrol_detection++;
  463. DS_Sleep(PR_MillisecondsToInterval(agmt_get_flowcontrolpause(agmt)));
  464. }
  465. PR_Unlock(rd->lock);
  466. }
  467. static int
  468. repl5_inc_waitfor_async_results(result_data *rd)
  469. {
  470. int done = 0;
  471. int loops = 0;
  472. int rc = UPDATE_NO_MORE_UPDATES;
  473. /* Keep pulling results off the LDAP connection until we catch up to the last message id stored in the rd */
  474. while (!done && !slapi_is_shutting_down())
  475. {
  476. /* Lock the structure to force memory barrier */
  477. PR_Lock(rd->lock);
  478. /* Are we caught up ? */
  479. slapi_log_error(SLAPI_LOG_REPL, NULL,
  480. "repl5_inc_waitfor_async_results: %d %d\n",
  481. rd->last_message_id_received, rd->last_message_id_sent);
  482. if (rd->last_message_id_received >= rd->last_message_id_sent)
  483. {
  484. /* If so then we're done */
  485. done = 1;
  486. } else if (rd->abort && (rd->result == UPDATE_CONNECTION_LOST))
  487. {
  488. done = 1; /* no connection == no more results */
  489. }
  490. /*
  491. * Return the last operation result
  492. */
  493. rc = rd->result;
  494. PR_Unlock(rd->lock);
  495. /* If not then sleep a bit */
  496. DS_Sleep(PR_SecondsToInterval(1));
  497. loops++;
  498. /* If we sleep forever then we can conclude that something bad happened, and bail... */
  499. /* Arbitrary 30 second delay : basically we should only expect to wait as long as it takes to process a few operations, which should be on the order of a second at most */
  500. if (!done && (loops > 300))
  501. {
  502. /* Log a warning */
  503. slapi_log_error(SLAPI_LOG_FATAL, NULL,
  504. "repl5_inc_waitfor_async_results timed out waiting for responses: %d %d\n",
  505. rd->last_message_id_received, rd->last_message_id_sent);
  506. done = 1;
  507. }
  508. }
  509. return rc;
  510. }
  511. /*
  512. * It's specifically ok to delete a protocol instance that
  513. * is currently running. The instance will be shut down, and
  514. * then resources will be freed. Since a graceful shutdown is
  515. * attempted, this function may take some time to complete.
  516. */
  517. static void
  518. repl5_inc_delete(Private_Repl_Protocol **prpp)
  519. {
  520. repl5_inc_private *prp_priv = (repl5_inc_private *)(*prpp)->private;
  521. /* if backoff is set, delete it (from EQ, as well) */
  522. if (prp_priv->backoff) {
  523. backoff_delete(&prp_priv->backoff);
  524. }
  525. /* First, stop the protocol if it isn't already stopped */
  526. if (!(*prpp)->stopped) {
  527. (*prpp)->stopped = 1;
  528. (*prpp)->stop(*prpp);
  529. }
  530. /* Then, delete all resources used by the protocol */
  531. if ((*prpp)->lock) {
  532. PR_DestroyLock((*prpp)->lock);
  533. (*prpp)->lock = NULL;
  534. }
  535. if ((*prpp)->cvar) {
  536. PR_DestroyCondVar((*prpp)->cvar);
  537. (*prpp)->cvar = NULL;
  538. }
  539. slapi_ch_free((void **)&(*prpp)->private);
  540. slapi_ch_free((void **)prpp);
  541. }
  542. /* helper function */
  543. void
  544. set_pause_and_busy_time(long *pausetime, long *busywaittime)
  545. {
  546. /* If neither are set, set busy time to its default */
  547. if (!*pausetime && !*busywaittime)
  548. {
  549. *busywaittime = PROTOCOL_BUSY_BACKOFF_MINIMUM;
  550. }
  551. /* pause time must be at least 1 more than the busy backoff time */
  552. if (*pausetime && !*busywaittime)
  553. {
  554. /*
  555. * user specified a pause time but no busy wait time - must
  556. * set busy wait time to 1 less than pause time - if pause
  557. * time is 1, we must set it to 2
  558. */
  559. if (*pausetime < 2)
  560. {
  561. *pausetime = 2;
  562. }
  563. *busywaittime = *pausetime - 1;
  564. }
  565. else if (!*pausetime && *busywaittime)
  566. {
  567. /*
  568. * user specified a busy wait time but no pause time - must
  569. * set pause time to 1 more than busy wait time
  570. */
  571. *pausetime = *busywaittime + 1;
  572. }
  573. else if (*pausetime && *busywaittime && *pausetime <= *busywaittime)
  574. {
  575. /*
  576. * user specified both pause and busy wait times, but the pause
  577. * time was <= busy wait time - pause time must be at least
  578. * 1 more than the busy wait time
  579. */
  580. *pausetime = *busywaittime + 1;
  581. }
  582. }
  583. /*
  584. * Do the incremental protocol.
  585. *
  586. * What's going on here? This thing is a state machine. It has the
  587. * following states:
  588. *
  589. * State transition table:
  590. *
  591. * Curr State Condition/Event Next State
  592. * ---------- ------------ -----------
  593. * START schedule window is open ACQUIRE_REPLICA
  594. * schedule window is closed WAIT_WINDOW_OPEN
  595. * WAIT_WINDOW_OPEN schedule change START
  596. * replicate now ACQUIRE_REPLICA
  597. * schedule window opens ACQUIRE_REPLICA
  598. * ACQUIRE_REPLICA acquired replica SEND_CHANGES
  599. * failed to acquire - transient error START_BACKOFF
  600. * failed to acquire - fatal error STOP_FATAL_ERROR
  601. * SEND_CHANGES can't update CONSUMER_NEEDS_REINIT
  602. * no changes to send WAIT_CHANGES
  603. * can't send - thransient error START_BACKOF
  604. * can't send - window closed WAIT_WINDOW_OPEN
  605. * can'r send - fatal error STOP_FATAL_ERROR
  606. * START_BACKOF replicate now ACQUIRE_REPLICA
  607. * schedule changes START
  608. * schedule window closes WAIT_WINDOW_OPEN
  609. * backoff expires & can acquire SEND_CHANGES
  610. * backoff expires & can't acquire-trans BACKOFF
  611. * backoff expires & can't acquire-fatal STOP_FATAL_ERROR
  612. * BACKOF replicate now ACQUIRE_REPLICA
  613. * schedule changes START
  614. * schedule window closes WAIT_WINDOW_OPEN
  615. * backoff expires & can acquire SEND_CHANGES
  616. * backoff expires & can't acquire-trans BACKOFF
  617. * backoff expires & can't acquire-fatal STOP_FATAL_ERROR
  618. * WAIT_CHANGES schedule window closes WAIT_WINDOW_OPEN
  619. * replicate_now ACQUIRE_REPLICA
  620. * change available ACQUIRE_REPLICA
  621. * schedule_change START
  622. */
  623. /*
  624. * Main state machine for the incremental protocol. This routine will,
  625. * under normal circumstances, not return until the protocol is shut
  626. * down.
  627. */
  628. static void
  629. repl5_inc_run(Private_Repl_Protocol *prp)
  630. {
  631. int current_state = STATE_START;
  632. int next_state = STATE_START;
  633. repl5_inc_private *prp_priv = (repl5_inc_private *)prp->private;
  634. int done;
  635. int e1;
  636. RUV *ruv = NULL;
  637. CSN *cons_schema_csn;
  638. Replica *replica = NULL;
  639. int wait_change_timer_set = 0;
  640. time_t last_start_time;
  641. PRUint32 num_changes_sent;
  642. /* use a different backoff timer strategy for ACQUIRE_REPLICA_BUSY errors */
  643. PRBool use_busy_backoff_timer = PR_FALSE;
  644. long pausetime = 0;
  645. long busywaittime = 0;
  646. long loops = 0;
  647. int optype, ldaprc;
  648. time_t next_fire_time;
  649. time_t now;
  650. prp->stopped = 0;
  651. prp->terminate = 0;
  652. /* establish_protocol_callbacks(prp); */
  653. done = 0;
  654. do {
  655. int rc;
  656. /* Take action, based on current state, and compute new state. */
  657. switch (current_state)
  658. {
  659. case STATE_START:
  660. dev_debug("repl5_inc_run(STATE_START)");
  661. if (PROTOCOL_IS_SHUTDOWN(prp)){
  662. done = 1;
  663. break;
  664. }
  665. /*
  666. * Our initial state. See if we're in a schedule window. If
  667. * so, then we're ready to acquire the replica and see if it
  668. * needs any updates from us. If not, then wait for the window
  669. * to open.
  670. */
  671. if (agmt_schedule_in_window_now(prp->agmt)){
  672. next_state = STATE_READY_TO_ACQUIRE;
  673. } else {
  674. next_state = STATE_WAIT_WINDOW_OPEN;
  675. }
  676. /* we can get here from other states because some events happened and were
  677. * not cleared. For instance when we wake up in STATE_WAIT_CHANGES state.
  678. * Since this is a fresh start state, we should clear all events */
  679. /* ONREPL - this does not feel right - we should take another look
  680. * at this state machine */
  681. reset_events (prp);
  682. /* Cancel any linger timer that might be in effect... */
  683. conn_cancel_linger(prp->conn);
  684. /* ... and disconnect, if currently connected */
  685. conn_disconnect(prp->conn);
  686. /* get the new pause time, if any */
  687. pausetime = agmt_get_pausetime(prp->agmt);
  688. /* get the new busy wait time, if any */
  689. busywaittime = agmt_get_busywaittime(prp->agmt);
  690. if (pausetime || busywaittime){
  691. /* helper function to make sure they are set correctly */
  692. set_pause_and_busy_time(&pausetime, &busywaittime);
  693. }
  694. break;
  695. case STATE_WAIT_WINDOW_OPEN:
  696. /*
  697. * We're waiting for a schedule window to open. If one did,
  698. * or we receive a "replicate now" event, then start a protocol
  699. * session immediately. If the replication schedule changed, go
  700. * back to start. Otherwise, go back to sleep.
  701. */
  702. dev_debug("repl5_inc_run(STATE_WAIT_WINDOW_OPEN)");
  703. if (PROTOCOL_IS_SHUTDOWN(prp)){
  704. done = 1;
  705. break;
  706. } else if (event_occurred(prp, EVENT_WINDOW_OPENED)){
  707. next_state = STATE_READY_TO_ACQUIRE;
  708. } else if (event_occurred(prp, EVENT_REPLICATE_NOW)){
  709. next_state = STATE_READY_TO_ACQUIRE;
  710. } else if (event_occurred(prp, EVENT_AGMT_CHANGED)){
  711. next_state = STATE_START;
  712. conn_set_agmt_changed(prp->conn);
  713. } else if (event_occurred(prp, EVENT_TRIGGERING_CRITERIA_MET)){ /* change available */
  714. /* just ignore it and go to sleep */
  715. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  716. } else if ((e1 = event_occurred(prp, EVENT_WINDOW_CLOSED)) ||
  717. event_occurred(prp, EVENT_BACKOFF_EXPIRED)){
  718. /* this events - should not occur - log a warning and go to sleep */
  719. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  720. "%s: Incremental protocol: "
  721. "event %s should not occur in state %s; going to sleep\n",
  722. agmt_get_long_name(prp->agmt), e1 ? event2name(EVENT_WINDOW_CLOSED) :
  723. event2name(EVENT_BACKOFF_EXPIRED), state2name(current_state));
  724. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  725. } else {
  726. /* wait until window opens or an event occurs */
  727. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  728. "%s: Incremental protocol: "
  729. "waiting for update window to open\n", agmt_get_long_name(prp->agmt));
  730. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  731. }
  732. break;
  733. case STATE_WAIT_CHANGES:
  734. /*
  735. * We're in a replication window, but we're waiting for more
  736. * changes to accumulate before we actually hook up and send
  737. * them.
  738. */
  739. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES)");
  740. if (PROTOCOL_IS_SHUTDOWN(prp)){
  741. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): PROTOCOL_IS_SHUTING_DOWN -> end repl5_inc_run\n");
  742. done = 1;
  743. break;
  744. } else if (event_occurred(prp, EVENT_REPLICATE_NOW)){
  745. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): EVENT_REPLICATE_NOW received -> STATE_READY_TO_ACQUIRE\n");
  746. next_state = STATE_READY_TO_ACQUIRE;
  747. wait_change_timer_set = 0;
  748. } else if (event_occurred(prp, EVENT_AGMT_CHANGED)){
  749. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): EVENT_AGMT_CHANGED received -> STATE_START\n");
  750. next_state = STATE_START;
  751. conn_set_agmt_changed(prp->conn);
  752. wait_change_timer_set = 0;
  753. } else if (event_occurred(prp, EVENT_WINDOW_CLOSED)){
  754. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): EVENT_WINDOW_CLOSED received -> STATE_WAIT_WINDOW_OPEN\n");
  755. next_state = STATE_WAIT_WINDOW_OPEN;
  756. wait_change_timer_set = 0;
  757. } else if (event_occurred(prp, EVENT_TRIGGERING_CRITERIA_MET)){
  758. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): EVENT_TRIGGERING_CRITERIA_MET received -> STATE_READY_TO_ACQUIRE\n");
  759. next_state = STATE_READY_TO_ACQUIRE;
  760. wait_change_timer_set = 0;
  761. } else if ((e1 = event_occurred(prp, EVENT_WINDOW_OPENED)) || event_occurred(prp, EVENT_BACKOFF_EXPIRED)){
  762. /* this events - should not occur - log a warning and clear the event */
  763. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name, "%s: Incremental protocol: "
  764. "event %s should not occur in state %s\n",agmt_get_long_name(prp->agmt),
  765. e1 ? event2name(EVENT_WINDOW_OPENED) : event2name(EVENT_BACKOFF_EXPIRED),
  766. state2name(current_state));
  767. wait_change_timer_set = 0;
  768. } else {
  769. if (wait_change_timer_set){
  770. /* We are here because our timer expired */
  771. dev_debug("repl5_inc_run(STATE_WAIT_CHANGES): wait_change_timer_set expired -> STATE_START\n");
  772. next_state = STATE_START;
  773. wait_change_timer_set = 0;
  774. } else {
  775. /*
  776. * We are here because the last replication session
  777. * finished or aborted.
  778. */
  779. wait_change_timer_set = 1;
  780. protocol_sleep(prp, MAX_WAIT_BETWEEN_SESSIONS);
  781. }
  782. }
  783. break;
  784. case STATE_READY_TO_ACQUIRE:
  785. dev_debug("repl5_inc_run(STATE_READY_TO_ACQUIRE)");
  786. if (PROTOCOL_IS_SHUTDOWN(prp)){
  787. done = 1;
  788. break;
  789. }
  790. /* ONREPL - at this state we unconditionally acquire the replica
  791. ignoring all events. Not sure if this is good */
  792. object_acquire(prp->replica_object);
  793. rc = acquire_replica(prp, REPL_NSDS50_INCREMENTAL_PROTOCOL_OID, &ruv);
  794. use_busy_backoff_timer = PR_FALSE; /* default */
  795. if (rc == ACQUIRE_SUCCESS){
  796. next_state = STATE_SENDING_UPDATES;
  797. } else if (rc == ACQUIRE_REPLICA_BUSY){
  798. next_state = STATE_BACKOFF_START;
  799. use_busy_backoff_timer = PR_TRUE;
  800. } else if (rc == ACQUIRE_CONSUMER_WAS_UPTODATE){
  801. next_state = STATE_WAIT_CHANGES;
  802. } else if (rc == ACQUIRE_TRANSIENT_ERROR){
  803. next_state = STATE_BACKOFF_START;
  804. } else if (rc == ACQUIRE_FATAL_ERROR){
  805. next_state = STATE_STOP_FATAL_ERROR;
  806. }
  807. if (rc != ACQUIRE_SUCCESS){
  808. int optype, ldaprc;
  809. conn_get_error(prp->conn, &optype, &ldaprc);
  810. agmt_set_last_update_status(prp->agmt, ldaprc,
  811. prp->last_acquire_response_code, NULL);
  812. }
  813. object_release(prp->replica_object);
  814. break;
  815. case STATE_BACKOFF_START:
  816. dev_debug("repl5_inc_run(STATE_BACKOFF_START)");
  817. if (PROTOCOL_IS_SHUTDOWN(prp)){
  818. done = 1;
  819. break;
  820. }
  821. if (event_occurred(prp, EVENT_REPLICATE_NOW)){
  822. next_state = STATE_READY_TO_ACQUIRE;
  823. } else if (event_occurred(prp, EVENT_AGMT_CHANGED)){
  824. next_state = STATE_START;
  825. conn_set_agmt_changed(prp->conn);
  826. } else if (event_occurred (prp, EVENT_WINDOW_CLOSED)){
  827. next_state = STATE_WAIT_WINDOW_OPEN;
  828. } else if (event_occurred (prp, EVENT_TRIGGERING_CRITERIA_MET)){
  829. /* consume and ignore */
  830. } else if ((e1 = event_occurred (prp, EVENT_WINDOW_OPENED)) ||
  831. event_occurred (prp, EVENT_BACKOFF_EXPIRED)){
  832. /* This should never happen */
  833. /* this events - should not occur - log a warning and go to sleep */
  834. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  835. "%s: Incremental protocol: event %s should not occur in state %s\n",
  836. agmt_get_long_name(prp->agmt),
  837. e1 ? event2name(EVENT_WINDOW_OPENED) : event2name(EVENT_BACKOFF_EXPIRED),
  838. state2name(current_state));
  839. } else {
  840. /* Set up the backoff timer to wake us up at the appropriate time */
  841. /* if previous backoff set up, delete it. */
  842. if (prp_priv->backoff) {
  843. backoff_delete(&prp_priv->backoff);
  844. }
  845. if (use_busy_backoff_timer){
  846. /* we received a busy signal from the consumer, wait for a while */
  847. if (!busywaittime){
  848. busywaittime = PROTOCOL_BUSY_BACKOFF_MINIMUM;
  849. }
  850. prp_priv->backoff = backoff_new(BACKOFF_FIXED, busywaittime , busywaittime);
  851. } else {
  852. prp_priv->backoff = backoff_new(BACKOFF_EXPONENTIAL, PROTOCOL_BACKOFF_MINIMUM,
  853. PROTOCOL_BACKOFF_MAXIMUM);
  854. }
  855. next_state = STATE_BACKOFF;
  856. backoff_reset(prp_priv->backoff, repl5_inc_backoff_expired, (void *)prp);
  857. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  858. use_busy_backoff_timer = PR_FALSE;
  859. }
  860. break;
  861. case STATE_BACKOFF:
  862. /*
  863. * We're in a backoff state.
  864. */
  865. dev_debug("repl5_inc_run(STATE_BACKOFF)");
  866. if (PROTOCOL_IS_SHUTDOWN(prp)){
  867. if (prp_priv->backoff)
  868. backoff_delete(&prp_priv->backoff);
  869. done = 1;
  870. break;
  871. } else if (event_occurred(prp, EVENT_REPLICATE_NOW)){
  872. next_state = STATE_READY_TO_ACQUIRE;
  873. } else if (event_occurred(prp, EVENT_AGMT_CHANGED)){
  874. next_state = STATE_START;
  875. conn_set_agmt_changed(prp->conn);
  876. /* Destroy the backoff timer, since we won't need it anymore */
  877. if (prp_priv->backoff)
  878. backoff_delete(&prp_priv->backoff);
  879. } else if (event_occurred(prp, EVENT_WINDOW_CLOSED)){
  880. next_state = STATE_WAIT_WINDOW_OPEN;
  881. /* Destroy the backoff timer, since we won't need it anymore */
  882. if (prp_priv->backoff)
  883. backoff_delete(&prp_priv->backoff);
  884. } else if (event_occurred(prp, EVENT_BACKOFF_EXPIRED)){
  885. rc = acquire_replica(prp, REPL_NSDS50_INCREMENTAL_PROTOCOL_OID, &ruv);
  886. use_busy_backoff_timer = PR_FALSE;
  887. if (rc == ACQUIRE_SUCCESS){
  888. next_state = STATE_SENDING_UPDATES;
  889. } else if (rc == ACQUIRE_REPLICA_BUSY){
  890. next_state = STATE_BACKOFF;
  891. use_busy_backoff_timer = PR_TRUE;
  892. } else if (rc == ACQUIRE_CONSUMER_WAS_UPTODATE){
  893. next_state = STATE_WAIT_CHANGES;
  894. } else if (rc == ACQUIRE_TRANSIENT_ERROR){
  895. next_state = STATE_BACKOFF;
  896. } else if (rc == ACQUIRE_FATAL_ERROR){
  897. next_state = STATE_STOP_FATAL_ERROR;
  898. }
  899. if (rc != ACQUIRE_SUCCESS){
  900. conn_get_error(prp->conn, &optype, &ldaprc);
  901. agmt_set_last_update_status(prp->agmt, ldaprc, prp->last_acquire_response_code, NULL);
  902. }
  903. /*
  904. * We either need to step the backoff timer, or
  905. * destroy it if we don't need it anymore
  906. */
  907. if (STATE_BACKOFF == next_state){
  908. /* Step the backoff timer */
  909. time(&now);
  910. next_fire_time = backoff_step(prp_priv->backoff);
  911. /* And go back to sleep */
  912. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  913. "%s: Replication session backing off for %ld seconds\n",
  914. agmt_get_long_name(prp->agmt),next_fire_time - now);
  915. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  916. } else {
  917. /* Destroy the backoff timer, since we won't need it anymore */
  918. backoff_delete(&prp_priv->backoff);
  919. }
  920. } else if (event_occurred(prp, EVENT_TRIGGERING_CRITERIA_MET)){
  921. /* changes are available */
  922. if ( prp_priv->backoff == NULL || backoff_expired (prp_priv->backoff, 60)){
  923. /*
  924. * Have seen cases that the agmt stuck here forever since
  925. * somehow the backoff timer was not in event queue anymore.
  926. * If the backoff timer has expired more than 60 seconds, destroy it.
  927. */
  928. if ( prp_priv->backoff )
  929. backoff_delete(&prp_priv->backoff);
  930. next_state = STATE_READY_TO_ACQUIRE;
  931. } else {
  932. /* ignore changes and go to sleep */
  933. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  934. }
  935. } else if (event_occurred(prp, EVENT_WINDOW_OPENED)){
  936. /* this should never happen - log an error and go to sleep */
  937. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name, "%s: Incremental protocol: "
  938. "event %s should not occur in state %s; going to sleep\n",
  939. agmt_get_long_name(prp->agmt), event2name(EVENT_WINDOW_OPENED),
  940. state2name(current_state));
  941. protocol_sleep(prp, PR_INTERVAL_NO_TIMEOUT);
  942. }
  943. break;
  944. case STATE_SENDING_UPDATES:
  945. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES)");
  946. agmt_set_update_in_progress(prp->agmt, PR_TRUE);
  947. num_changes_sent = 0;
  948. last_start_time = current_time();
  949. agmt_set_last_update_start(prp->agmt, last_start_time);
  950. /*
  951. * We've acquired the replica, and are ready to send any needed updates.
  952. */
  953. if (PROTOCOL_IS_SHUTDOWN(prp)){
  954. release_replica (prp);
  955. done = 1;
  956. agmt_set_update_in_progress(prp->agmt, PR_FALSE);
  957. agmt_set_last_update_end(prp->agmt, current_time());
  958. /* MAB: I don't find the following status correct. How do we know it has
  959. * been stopped by an admin and not by a total update request, for instance?
  960. * In any case, how is this protocol shutdown situation different from all the
  961. * other ones that are present in this state machine? */
  962. /* richm: We at least need to let monitors know that the protocol has been
  963. * shutdown - maybe they can figure out why */
  964. agmt_set_last_update_status(prp->agmt, 0, 0, "Protocol stopped");
  965. agmt_update_done(prp->agmt, 0);
  966. break;
  967. }
  968. agmt_set_last_update_status(prp->agmt, 0, 0, "Incremental update started");
  969. /* ONREPL - in this state we send changes no matter what other events occur.
  970. * This is because we can get because of the REPLICATE_NOW event which
  971. * has high priority. Is this ok? */
  972. /* First, push new schema to the consumer if needed */
  973. /* ONREPL - should we push schema after we examine the RUV? */
  974. /*
  975. * GGOOREPL - I don't see why we should wait until we've
  976. * examined the RUV. The schema entry has its own CSN that is
  977. * used to decide if the remote schema needs to be updated.
  978. */
  979. cons_schema_csn = agmt_get_consumer_schema_csn ( prp->agmt );
  980. rc = conn_push_schema(prp->conn, &cons_schema_csn);
  981. if ( cons_schema_csn != agmt_get_consumer_schema_csn ( prp->agmt )){
  982. agmt_set_consumer_schema_csn ( prp->agmt, cons_schema_csn );
  983. }
  984. if (CONN_SCHEMA_UPDATED != rc && CONN_SCHEMA_NO_UPDATE_NEEDED != rc){
  985. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  986. "%s: Warning: unable to replicate schema: rc=%d\n", agmt_get_long_name(prp->agmt), rc);
  987. /* But keep going */
  988. }
  989. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> examine_update_vector");
  990. rc = examine_update_vector(prp, ruv);
  991. /*
  992. * Decide what to do next - proceed with incremental, backoff, or total update
  993. */
  994. switch (rc){
  995. case EXAMINE_RUV_PARAM_ERROR:
  996. /* this is really bad - we have NULL prp! */
  997. next_state = STATE_STOP_FATAL_ERROR;
  998. break;
  999. case EXAMINE_RUV_PRISTINE_REPLICA:
  1000. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1001. "%s: Replica has no update vector. It has never been initialized.\n",
  1002. agmt_get_long_name(prp->agmt));
  1003. next_state = STATE_BACKOFF_START;
  1004. break;
  1005. case EXAMINE_RUV_GENERATION_MISMATCH:
  1006. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1007. "%s: Replica has a different generation ID than the local data.\n",
  1008. agmt_get_long_name(prp->agmt));
  1009. next_state = STATE_BACKOFF_START;
  1010. break;
  1011. case EXAMINE_RUV_REPLICA_TOO_OLD:
  1012. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1013. "%s: Replica update vector is too out of date to bring "
  1014. "into sync using the incremental protocol. The replica "
  1015. "must be reinitialized.\n", agmt_get_long_name(prp->agmt));
  1016. next_state = STATE_BACKOFF_START;
  1017. break;
  1018. case EXAMINE_RUV_OK:
  1019. /* update our csn generator state with the consumer's ruv data */
  1020. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> examine_update_vector OK");
  1021. object_acquire(prp->replica_object);
  1022. replica = object_get_data(prp->replica_object);
  1023. rc = replica_update_csngen_state (replica, ruv);
  1024. object_release (prp->replica_object);
  1025. replica = NULL;
  1026. if (rc == CSN_LIMIT_EXCEEDED) /* too much skew */ {
  1027. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1028. "%s: Incremental protocol: fatal error - too much time skew between replicas!\n",
  1029. agmt_get_long_name(prp->agmt));
  1030. next_state = STATE_STOP_FATAL_ERROR;
  1031. } else if (rc != 0) /* internal error */ {
  1032. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1033. "%s: Incremental protocol: fatal internal error updating the CSN generator!\n",
  1034. agmt_get_long_name(prp->agmt));
  1035. next_state = STATE_STOP_FATAL_ERROR;
  1036. } else {
  1037. rc = send_updates(prp, ruv, &num_changes_sent);
  1038. if (rc == UPDATE_NO_MORE_UPDATES){
  1039. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_NO_MORE_UPDATES -> STATE_WAIT_CHANGES");
  1040. agmt_set_last_update_status(prp->agmt, 0, 0, "Incremental update succeeded");
  1041. next_state = STATE_WAIT_CHANGES;
  1042. } else if (rc == UPDATE_YIELD){
  1043. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_YIELD -> STATE_BACKOFF_START");
  1044. agmt_set_last_update_status(prp->agmt, 0, 0, "Incremental update succeeded and yielded");
  1045. use_busy_backoff_timer = PR_TRUE;
  1046. next_state = STATE_BACKOFF_START;
  1047. } else if (rc == UPDATE_TRANSIENT_ERROR){
  1048. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_TRANSIENT_ERROR -> STATE_BACKOFF_START");
  1049. next_state = STATE_BACKOFF_START;
  1050. } else if (rc == UPDATE_FATAL_ERROR){
  1051. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_FATAL_ERROR -> STATE_STOP_FATAL_ERROR");
  1052. next_state = STATE_STOP_FATAL_ERROR;
  1053. } else if (rc == UPDATE_SCHEDULE_WINDOW_CLOSED){
  1054. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_SCHEDULE_WINDOW_CLOSED -> STATE_WAIT_WINDOW_OPEN");
  1055. /*
  1056. * ONREPL - I don't think we should check this. We might be
  1057. * here because of replicate_now event - so we don't care
  1058. * about the schedule
  1059. */
  1060. next_state = STATE_WAIT_WINDOW_OPEN;
  1061. /* ONREPL - do we need to release the replica here ? */
  1062. conn_disconnect (prp->conn);
  1063. } else if (rc == UPDATE_CONNECTION_LOST){
  1064. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_CONNECTION_LOST -> STATE_BACKOFF_START");
  1065. next_state = STATE_BACKOFF_START;
  1066. } else if (rc == UPDATE_TIMEOUT){
  1067. dev_debug("repl5_inc_run(STATE_SENDING_UPDATES) -> send_updates = UPDATE_TIMEOUT -> STATE_BACKOFF_START");
  1068. next_state = STATE_BACKOFF_START;
  1069. }
  1070. }
  1071. last_start_time = 0UL;
  1072. break;
  1073. }
  1074. if (NULL != ruv){
  1075. ruv_destroy(&ruv); ruv = NULL;
  1076. }
  1077. agmt_set_last_update_end(prp->agmt, current_time());
  1078. agmt_set_update_in_progress(prp->agmt, PR_FALSE);
  1079. agmt_update_done(prp->agmt, 0);
  1080. /* If timed out, close the connection after released the replica */
  1081. release_replica(prp);
  1082. if (rc == UPDATE_TIMEOUT) {
  1083. conn_disconnect(prp->conn);
  1084. }
  1085. if (rc == UPDATE_NO_MORE_UPDATES && num_changes_sent > 0){
  1086. if (pausetime > 0){
  1087. /* richm - 20020219 - If we have acquired the consumer, and another master has gone
  1088. * into backoff waiting for us to release it, we may acquire the replica sooner
  1089. * than the other master has a chance to, and the other master may not be able
  1090. * to acquire the consumer for a long time (hours, days?) if this server is
  1091. * under a heavy load (see reliab06 et. al. system tests)
  1092. * So, this sleep gives the other master(s) a chance to acquire the consumer replica */
  1093. loops = pausetime;
  1094. /* the while loop is so that we don't just sleep and sleep if an
  1095. * event comes in that we should handle immediately (like shutdown) */
  1096. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1097. "%s: Pausing updates for %ld seconds to allow other suppliers to update consumer\n",
  1098. agmt_get_long_name(prp->agmt), pausetime);
  1099. while (loops-- && !(PROTOCOL_IS_SHUTDOWN(prp))){
  1100. DS_Sleep(PR_SecondsToInterval(1));
  1101. }
  1102. } else if (num_changes_sent > 10){
  1103. /* wait for consumer to write its ruv if the replication was busy */
  1104. /* When asked, consumer sends its ruv in cache to the supplier. */
  1105. /* DS_Sleep ( PR_SecondsToInterval(1) ); */
  1106. }
  1107. }
  1108. break;
  1109. case STATE_STOP_FATAL_ERROR:
  1110. /*
  1111. * We encountered some sort of a fatal error. Suspend.
  1112. */
  1113. /* XXXggood update state in replica */
  1114. agmt_set_last_update_status(prp->agmt, -1, 0, "Incremental update has failed and requires administrator action");
  1115. dev_debug("repl5_inc_run(STATE_STOP_FATAL_ERROR)");
  1116. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1117. "%s: Incremental update failed and requires administrator action\n",
  1118. agmt_get_long_name(prp->agmt));
  1119. next_state = STATE_STOP_FATAL_ERROR_PART2;
  1120. break;
  1121. case STATE_STOP_FATAL_ERROR_PART2:
  1122. if (PROTOCOL_IS_SHUTDOWN(prp)){
  1123. done = 1;
  1124. break;
  1125. }
  1126. /* MAB: This state is the FATAL state where we are supposed to get
  1127. * as a result of a FATAL error on send_updates. But, as bug
  1128. * states, send_updates was always returning TRANSIENT errors and never
  1129. * FATAL... In other words, this code has never been tested before...
  1130. *
  1131. * As of 01/16/01, this piece of code was in a very dangerous state. In particular,
  1132. * 1) it does not catch any events
  1133. * 2) it is a terminal state (once reached it never transitions to a different state)
  1134. *
  1135. * Both things combined make this state to become a consuming infinite loop
  1136. * that is useless after all (we are in a fatal place requiring manual admin jobs */
  1137. /* MAB: The following lines fix problem number 1 above... When the code gets
  1138. * into this state, it should only get a chance to get out of it by an
  1139. * EVENT_AGMT_CHANGED event... All other events should be ignored */
  1140. else if (event_occurred(prp, EVENT_AGMT_CHANGED)){
  1141. dev_debug("repl5_inc_run(STATE_STOP_FATAL_ERROR): EVENT_AGMT_CHANGED received\n");
  1142. /* Chance to recover for the EVENT_AGMT_CHANGED event.
  1143. * This is not mandatory, but fixes problem 2 above */
  1144. next_state = STATE_STOP_NORMAL_TERMINATION;
  1145. } else {
  1146. dev_debug("repl5_inc_run(STATE_STOP_FATAL_ERROR): Event received. Clearing it\n");
  1147. reset_events (prp);
  1148. }
  1149. protocol_sleep (prp, PR_INTERVAL_NO_TIMEOUT);
  1150. break;
  1151. case STATE_STOP_NORMAL_TERMINATION:
  1152. /*
  1153. * We encountered some sort of a fatal error. Return.
  1154. */
  1155. /* XXXggood update state in replica */
  1156. dev_debug("repl5_inc_run(STATE_STOP_NORMAL_TERMINATION)");
  1157. done = 1;
  1158. break;
  1159. }
  1160. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,"%s: State: %s -> %s\n",
  1161. agmt_get_long_name(prp->agmt),state2name(current_state), state2name(next_state));
  1162. current_state = next_state;
  1163. } while (!done);
  1164. /* remove_protocol_callbacks(prp); */
  1165. prp->stopped = 1;
  1166. /* Cancel any linger timer that might be in effect... */
  1167. conn_cancel_linger(prp->conn);
  1168. /* ... and disconnect, if currently connected */
  1169. conn_disconnect(prp->conn);
  1170. }
  1171. /*
  1172. * Go to sleep until awakened.
  1173. */
  1174. static void
  1175. protocol_sleep(Private_Repl_Protocol *prp, PRIntervalTime duration)
  1176. {
  1177. PR_ASSERT(NULL != prp);
  1178. PR_Lock(prp->lock);
  1179. /* we should not go to sleep if there are events available to be processed.
  1180. Otherwise, we can miss the event that suppose to wake us up */
  1181. if (prp->eventbits == 0)
  1182. PR_WaitCondVar(prp->cvar, duration);
  1183. else
  1184. {
  1185. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1186. "%s: Incremental protocol: can't go to sleep: event bits - %x\n",
  1187. agmt_get_long_name(prp->agmt), prp->eventbits);
  1188. }
  1189. PR_Unlock(prp->lock);
  1190. }
  1191. /*
  1192. * Notify the protocol about some event. Signal the condition
  1193. * variable in case the protocol is sleeping. Multiple occurences
  1194. * of a single event type are not remembered (e.g. no stack
  1195. * of events is maintained).
  1196. */
  1197. static void
  1198. event_notify(Private_Repl_Protocol *prp, PRUint32 event)
  1199. {
  1200. PR_ASSERT(NULL != prp);
  1201. PR_Lock(prp->lock);
  1202. prp->eventbits |= event;
  1203. PR_NotifyCondVar(prp->cvar);
  1204. PR_Unlock(prp->lock);
  1205. }
  1206. /*
  1207. * Test to see if an event occurred. The event is cleared when
  1208. * read.
  1209. */
  1210. static PRUint32
  1211. event_occurred(Private_Repl_Protocol *prp, PRUint32 event)
  1212. {
  1213. PRUint32 return_value;
  1214. PR_ASSERT(NULL != prp);
  1215. PR_Lock(prp->lock);
  1216. return_value = (prp->eventbits & event);
  1217. prp->eventbits &= ~event; /* Clear event */
  1218. PR_Unlock(prp->lock);
  1219. return return_value;
  1220. }
  1221. static void
  1222. reset_events (Private_Repl_Protocol *prp)
  1223. {
  1224. PR_ASSERT(NULL != prp);
  1225. PR_Lock(prp->lock);
  1226. prp->eventbits = 0;
  1227. PR_Unlock(prp->lock);
  1228. }
  1229. /*
  1230. * Replay the actual update to the consumer. Construct an appropriate LDAP
  1231. * operation, attach the baggage LDAPv3 control that contains the CSN, etc.,
  1232. * and send the operation to the consumer.
  1233. */
  1234. ConnResult
  1235. replay_update(Private_Repl_Protocol *prp, slapi_operation_parameters *op, int *message_id)
  1236. {
  1237. ConnResult return_value = CONN_OPERATION_FAILED;
  1238. LDAPControl *update_control;
  1239. char *parentuniqueid;
  1240. LDAPMod **modrdn_mods = NULL;
  1241. char csn_str[CSN_STRSIZE]; /* For logging only */
  1242. if (message_id) {
  1243. /* if we get out of this function without setting message_id, it means
  1244. we didn't send an op, so no result needs to be processed */
  1245. *message_id = 0;
  1246. }
  1247. /* Construct the replication info control that accompanies the operation */
  1248. if (SLAPI_OPERATION_ADD == op->operation_type)
  1249. {
  1250. parentuniqueid = op->p.p_add.parentuniqueid;
  1251. }
  1252. else if (SLAPI_OPERATION_MODRDN == op->operation_type)
  1253. {
  1254. /*
  1255. * For modrdn operations, we need to send along modified attributes, e.g.
  1256. * modifytimestamp.
  1257. * And the superior_uniqueid !
  1258. */
  1259. modrdn_mods = op->p.p_modrdn.modrdn_mods;
  1260. parentuniqueid = op->p.p_modrdn.modrdn_newsuperior_address.uniqueid;
  1261. }
  1262. else
  1263. {
  1264. parentuniqueid = NULL;
  1265. }
  1266. if (create_NSDS50ReplUpdateInfoControl(op->target_address.uniqueid,
  1267. parentuniqueid, op->csn, modrdn_mods, &update_control) != LDAP_SUCCESS)
  1268. {
  1269. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1270. "%s: replay_update: Unable to create NSDS50ReplUpdateInfoControl "
  1271. "for operation with csn %s. Skipping update.\n",
  1272. agmt_get_long_name(prp->agmt), csn_as_string(op->csn, PR_FALSE, csn_str));
  1273. }
  1274. else
  1275. {
  1276. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1277. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1278. "%s: replay_update: Sending %s operation (dn=\"%s\" csn=%s)\n",
  1279. agmt_get_long_name(prp->agmt),
  1280. op2string(op->operation_type), REPL_GET_DN(&op->target_address),
  1281. csn_as_string(op->csn, PR_FALSE, csn_str));
  1282. }
  1283. /* What type of operation is it? */
  1284. switch (op->operation_type)
  1285. {
  1286. case SLAPI_OPERATION_ADD:
  1287. {
  1288. LDAPMod **entryattrs;
  1289. /* Convert entry to mods */
  1290. (void)slapi_entry2mods (op->p.p_add.target_entry,
  1291. NULL /* &entrydn : We don't need it */,
  1292. &entryattrs);
  1293. if (NULL == entryattrs)
  1294. {
  1295. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1296. "%s: replay_update: Cannot convert entry to LDAPMods.\n",
  1297. agmt_get_long_name(prp->agmt));
  1298. return_value = CONN_LOCAL_ERROR;
  1299. }
  1300. else
  1301. {
  1302. /* If fractional agreement, trim down the entry */
  1303. if (agmt_is_fractional(prp->agmt))
  1304. {
  1305. repl5_strip_fractional_mods(prp->agmt,entryattrs);
  1306. }
  1307. if (MODS_ARE_EMPTY(entryattrs)) {
  1308. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1309. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1310. "%s: replay_update: %s operation (dn=\"%s\" csn=%s) "
  1311. "not sent - empty\n",
  1312. agmt_get_long_name(prp->agmt),
  1313. op2string(op->operation_type),
  1314. REPL_GET_DN(&op->target_address),
  1315. csn_as_string(op->csn, PR_FALSE, csn_str));
  1316. }
  1317. return_value = CONN_OPERATION_SUCCESS;
  1318. } else {
  1319. return_value = conn_send_add(prp->conn, REPL_GET_DN(&op->target_address),
  1320. entryattrs, update_control, message_id);
  1321. }
  1322. ldap_mods_free(entryattrs, 1);
  1323. }
  1324. break;
  1325. }
  1326. case SLAPI_OPERATION_MODIFY:
  1327. /* If fractional agreement, trim down the mods */
  1328. if (agmt_is_fractional(prp->agmt))
  1329. {
  1330. repl5_strip_fractional_mods(prp->agmt,op->p.p_modify.modify_mods);
  1331. }
  1332. if (MODS_ARE_EMPTY(op->p.p_modify.modify_mods)) {
  1333. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1334. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1335. "%s: replay_update: %ss operation (dn=\"%s\" csn=%s) "
  1336. "not sent - empty\n",
  1337. agmt_get_long_name(prp->agmt),
  1338. op2string(op->operation_type),
  1339. REPL_GET_DN(&op->target_address),
  1340. csn_as_string(op->csn, PR_FALSE, csn_str));
  1341. }
  1342. return_value = CONN_OPERATION_SUCCESS;
  1343. } else {
  1344. return_value = conn_send_modify(prp->conn, REPL_GET_DN(&op->target_address),
  1345. op->p.p_modify.modify_mods, update_control, message_id);
  1346. }
  1347. break;
  1348. case SLAPI_OPERATION_DELETE:
  1349. return_value = conn_send_delete(prp->conn, REPL_GET_DN(&op->target_address),
  1350. update_control, message_id);
  1351. break;
  1352. case SLAPI_OPERATION_MODRDN:
  1353. /* XXXggood need to pass modrdn mods in update control! */
  1354. return_value = conn_send_rename(prp->conn, REPL_GET_DN(&op->target_address),
  1355. op->p.p_modrdn.modrdn_newrdn,
  1356. REPL_GET_DN(&op->p.p_modrdn.modrdn_newsuperior_address),
  1357. op->p.p_modrdn.modrdn_deloldrdn,
  1358. update_control, message_id);
  1359. break;
  1360. default:
  1361. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name, "%s: replay_update: Unknown "
  1362. "operation type %lu found in changelog - skipping change.\n",
  1363. agmt_get_long_name(prp->agmt), op->operation_type);
  1364. }
  1365. destroy_NSDS50ReplUpdateInfoControl(&update_control);
  1366. }
  1367. if (CONN_OPERATION_SUCCESS == return_value)
  1368. {
  1369. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1370. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1371. "%s: replay_update: Consumer successfully sent operation with csn %s\n",
  1372. agmt_get_long_name(prp->agmt), csn_as_string(op->csn, PR_FALSE, csn_str));
  1373. }
  1374. }
  1375. else
  1376. {
  1377. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1378. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1379. "%s: replay_update: Consumer could not replay operation with csn %s\n",
  1380. agmt_get_long_name(prp->agmt), csn_as_string(op->csn, PR_FALSE, csn_str));
  1381. }
  1382. }
  1383. return return_value;
  1384. }
  1385. static PRBool
  1386. is_dummy_operation (const slapi_operation_parameters *op)
  1387. {
  1388. return (strcmp (op->target_address.uniqueid, START_ITERATION_ENTRY_UNIQUEID) == 0);
  1389. }
  1390. void
  1391. cl5_operation_parameters_done (struct slapi_operation_parameters *sop)
  1392. {
  1393. if(sop!=NULL) {
  1394. switch(sop->operation_type)
  1395. {
  1396. case SLAPI_OPERATION_BIND:
  1397. slapi_ch_free((void **)&(sop->p.p_bind.bind_saslmechanism));
  1398. if (sop->p.p_bind.bind_creds)
  1399. ber_bvecfree((struct berval**)&(sop->p.p_bind.bind_creds));
  1400. if (sop->p.p_bind.bind_ret_saslcreds)
  1401. ber_bvecfree((struct berval**)&(sop->p.p_bind.bind_ret_saslcreds));
  1402. sop->p.p_bind.bind_creds = NULL;
  1403. sop->p.p_bind.bind_ret_saslcreds = NULL;
  1404. break;
  1405. case SLAPI_OPERATION_COMPARE:
  1406. ava_done((struct ava *)&(sop->p.p_compare.compare_ava));
  1407. break;
  1408. case SLAPI_OPERATION_SEARCH:
  1409. slapi_ch_free((void **)&(sop->p.p_search.search_strfilter));
  1410. charray_free(sop->p.p_search.search_attrs);
  1411. slapi_filter_free(sop->p.p_search.search_filter,1);
  1412. break;
  1413. case SLAPI_OPERATION_MODRDN:
  1414. sop->p.p_modrdn.modrdn_deloldrdn = 0;
  1415. break;
  1416. case SLAPI_OPERATION_EXTENDED:
  1417. slapi_ch_free((void **)&(sop->p.p_extended.exop_oid));
  1418. if (sop->p.p_extended.exop_value)
  1419. ber_bvecfree((struct berval**)&(sop->p.p_extended.exop_value));
  1420. sop->p.p_extended.exop_value = NULL;
  1421. break;
  1422. default:
  1423. break;
  1424. }
  1425. }
  1426. operation_parameters_done(sop);
  1427. }
  1428. /* Helper to update the agreement state based on a the result of a replay operation */
  1429. static int
  1430. repl5_inc_update_from_op_result(Private_Repl_Protocol *prp, ConnResult replay_crc, int connection_error, char *csn_str, char *uniqueid, ReplicaId replica_id, int* finished, PRUint32 *num_changes_sent)
  1431. {
  1432. int return_value = 0;
  1433. if (CONN_OPERATION_SUCCESS != replay_crc)
  1434. {
  1435. /* Figure out what to do next */
  1436. if (CONN_OPERATION_FAILED == replay_crc)
  1437. {
  1438. /* Map ldap error code to return value */
  1439. if (!ignore_error_and_keep_going(connection_error))
  1440. {
  1441. return_value = UPDATE_TRANSIENT_ERROR;
  1442. *finished = 1;
  1443. }
  1444. else
  1445. {
  1446. agmt_inc_last_update_changecount (prp->agmt, replica_id, 1 /*skipped*/);
  1447. }
  1448. slapi_log_error(*finished ? SLAPI_LOG_FATAL : slapi_log_urp, repl_plugin_name,
  1449. "%s: Consumer failed to replay change (uniqueid %s, CSN %s): %s (%d). %s.\n",
  1450. agmt_get_long_name(prp->agmt),
  1451. uniqueid, csn_str,
  1452. ldap_err2string(connection_error), connection_error,
  1453. *finished ? "Will retry later" : "Skipping");
  1454. }
  1455. else if (CONN_NOT_CONNECTED == replay_crc)
  1456. {
  1457. /* We lost the connection - enter backoff state */
  1458. return_value = UPDATE_CONNECTION_LOST;
  1459. *finished = 1;
  1460. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1461. "%s: Consumer failed to replay change (uniqueid %s, CSN %s): "
  1462. "%s(%d). Will retry later.\n",
  1463. agmt_get_long_name(prp->agmt),
  1464. uniqueid, csn_str,
  1465. connection_error ? ldap_err2string(connection_error) : "Connection lost",
  1466. connection_error);
  1467. }
  1468. else if (CONN_TIMEOUT == replay_crc)
  1469. {
  1470. return_value = UPDATE_TIMEOUT;
  1471. *finished = 1;
  1472. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1473. "%s: Consumer timed out to replay change (uniqueid %s, CSN %s): "
  1474. "%s.\n",
  1475. agmt_get_long_name(prp->agmt),
  1476. uniqueid, csn_str,
  1477. connection_error ? ldap_err2string(connection_error) : "Timeout");
  1478. }
  1479. else if (CONN_LOCAL_ERROR == replay_crc)
  1480. {
  1481. /*
  1482. * Something bad happened on the local server - enter
  1483. * backoff state.
  1484. */
  1485. return_value = UPDATE_TRANSIENT_ERROR;
  1486. *finished = 1;
  1487. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1488. "%s: Failed to replay change (uniqueid %s, CSN %s): "
  1489. "Local error. Will retry later.\n",
  1490. agmt_get_long_name(prp->agmt),
  1491. uniqueid, csn_str);
  1492. }
  1493. if (*finished){
  1494. /*
  1495. * A serious error has occurred, the consumer might have closed
  1496. * the connection already, but we need to close the conn on the
  1497. * supplier side to properly set the conn structure as closed.
  1498. */
  1499. conn_disconnect(prp->conn);
  1500. }
  1501. }
  1502. else
  1503. {
  1504. /* Positive response received */
  1505. (*num_changes_sent)++;
  1506. agmt_inc_last_update_changecount (prp->agmt, replica_id, 0 /*replayed*/);
  1507. }
  1508. return return_value;
  1509. }
  1510. /*
  1511. * Send a set of updates to the replica. Assumes that (1) the replica
  1512. * has already been acquired, (2) that the consumer's update vector has
  1513. * been checked and (3) that it's ok to send incremental updates.
  1514. * Returns:
  1515. * UPDATE_NO_MORE_UPDATES - all updates were sent successfully
  1516. * UPDATE_TRANSIENT_ERROR - some non-permanent error occurred. Try again later.
  1517. * UPDATE_FATAL_ERROR - some bad, permanent error occurred.
  1518. * UPDATE_SCHEDULE_WINDOW_CLOSED - the schedule window closed on us.
  1519. */
  1520. static int
  1521. send_updates(Private_Repl_Protocol *prp, RUV *remote_update_vector, PRUint32 *num_changes_sent)
  1522. {
  1523. CL5Entry entry;
  1524. slapi_operation_parameters op;
  1525. int return_value = 0;
  1526. int rc;
  1527. CL5ReplayIterator *changelog_iterator;
  1528. int message_id = 0;
  1529. result_data *rd = NULL;
  1530. *num_changes_sent = 0;
  1531. /*
  1532. * Iterate over the changelog. Retrieve each update,
  1533. * construct an appropriate LDAP operation,
  1534. * attaching the CSN, and send the change.
  1535. */
  1536. rc = cl5CreateReplayIterator(prp, remote_update_vector, &changelog_iterator);
  1537. if (CL5_SUCCESS != rc)
  1538. {
  1539. switch (rc)
  1540. {
  1541. case CL5_BAD_DATA: /* invalid parameter passed to the function */
  1542. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1543. "%s: Invalid parameter passed to cl5CreateReplayIterator\n",
  1544. agmt_get_long_name(prp->agmt));
  1545. return_value = UPDATE_FATAL_ERROR;
  1546. break;
  1547. case CL5_BAD_FORMAT: /* db data has unexpected format */
  1548. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1549. "%s: Unexpected format encountered in changelog database\n",
  1550. agmt_get_long_name(prp->agmt));
  1551. return_value = UPDATE_FATAL_ERROR;
  1552. break;
  1553. case CL5_BAD_STATE: /* changelog is in an incorrect state for attempted operation */
  1554. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1555. "%s: Changelog database was in an incorrect state\n",
  1556. agmt_get_long_name(prp->agmt));
  1557. return_value = UPDATE_FATAL_ERROR;
  1558. break;
  1559. case CL5_BAD_DBVERSION: /* changelog has invalid dbversion */
  1560. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1561. "%s: Incorrect dbversion found in changelog database\n",
  1562. agmt_get_long_name(prp->agmt));
  1563. return_value = UPDATE_FATAL_ERROR;
  1564. break;
  1565. case CL5_DB_ERROR: /* database error */
  1566. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1567. "%s: A changelog database error was encountered\n",
  1568. agmt_get_long_name(prp->agmt));
  1569. return_value = UPDATE_FATAL_ERROR;
  1570. break;
  1571. case CL5_NOTFOUND: /* we have no changes to send */
  1572. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1573. "%s: No changes to send\n",
  1574. agmt_get_long_name(prp->agmt));
  1575. return_value = UPDATE_NO_MORE_UPDATES;
  1576. break;
  1577. case CL5_MEMORY_ERROR: /* memory allocation failed */
  1578. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1579. "%s: Memory allocation error occurred\n",
  1580. agmt_get_long_name(prp->agmt));
  1581. return_value = UPDATE_FATAL_ERROR;
  1582. break;
  1583. case CL5_SYSTEM_ERROR: /* NSPR error occurred: use PR_GetError for further info */
  1584. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1585. "%s: An NSPR error (%d) occurred\n",
  1586. agmt_get_long_name(prp->agmt), PR_GetError());
  1587. return_value = UPDATE_TRANSIENT_ERROR;
  1588. break;
  1589. case CL5_CSN_ERROR: /* CSN API failed */
  1590. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1591. "%s: A CSN API failure was encountered\n",
  1592. agmt_get_long_name(prp->agmt));
  1593. return_value = UPDATE_TRANSIENT_ERROR;
  1594. break;
  1595. case CL5_RUV_ERROR: /* RUV API failed */
  1596. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1597. "%s: An RUV API failure occurred\n",
  1598. agmt_get_long_name(prp->agmt));
  1599. return_value = UPDATE_TRANSIENT_ERROR;
  1600. break;
  1601. case CL5_OBJSET_ERROR: /* namedobjset api failed */
  1602. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1603. "%s: A namedobject API failure occurred\n",
  1604. agmt_get_long_name(prp->agmt));
  1605. return_value = UPDATE_TRANSIENT_ERROR;
  1606. break;
  1607. case CL5_PURGED_DATA: /* requested data has been purged */
  1608. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1609. "%s: Data required to update replica has been purged. "
  1610. "The replica must be reinitialized.\n",
  1611. agmt_get_long_name(prp->agmt));
  1612. return_value = UPDATE_TRANSIENT_ERROR;
  1613. break;
  1614. case CL5_MISSING_DATA: /* data should be in the changelog, but is missing */
  1615. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1616. "send_updates - %s: Missing data encountered. "
  1617. "If the error persists the replica must be reinitialized.\n",
  1618. agmt_get_long_name(prp->agmt));
  1619. return_value = UPDATE_TRANSIENT_ERROR;
  1620. break;
  1621. case CL5_UNKNOWN_ERROR: /* unclassified error */
  1622. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1623. "%s: An unknown error was encountered\n",
  1624. agmt_get_long_name(prp->agmt));
  1625. return_value = UPDATE_TRANSIENT_ERROR;
  1626. break;
  1627. default:
  1628. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1629. "%s: An unknown error (%d) occurred "
  1630. "(cl5CreateReplayIterator)\n",
  1631. agmt_get_long_name(prp->agmt), rc);
  1632. return_value = UPDATE_TRANSIENT_ERROR;
  1633. }
  1634. }
  1635. else
  1636. {
  1637. ConnResult replay_crc;
  1638. Replica *replica = (Replica*) object_get_data(prp->replica_object);
  1639. PRBool subentry_update_needed = PR_FALSE;
  1640. PRUint64 release_timeout = replica_get_release_timeout(replica);
  1641. char csn_str[CSN_STRSIZE];
  1642. int skipped_updates = 0;
  1643. int fractional_repl;
  1644. int finished = 0;
  1645. #define FRACTIONAL_SKIPPED_THRESHOLD 100
  1646. /* Start the results reading thread */
  1647. rd = repl5_inc_rd_new(prp);
  1648. if (!prp->repl50consumer)
  1649. {
  1650. rc = repl5_inc_create_async_result_thread(rd);
  1651. if (rc) {
  1652. slapi_log_error (SLAPI_LOG_FATAL, repl_plugin_name, "%s: repl5_inc_run: "
  1653. "repl5_tot_create_async_result_thread failed; error - %d\n",
  1654. agmt_get_long_name(prp->agmt), rc);
  1655. return_value = UPDATE_FATAL_ERROR;
  1656. }
  1657. }
  1658. memset ( (void*)&op, 0, sizeof (op) );
  1659. entry.op = &op;
  1660. fractional_repl = agmt_is_fractional(prp->agmt);
  1661. do {
  1662. cl5_operation_parameters_done ( entry.op );
  1663. memset ( (void*)entry.op, 0, sizeof (op) );
  1664. rc = cl5GetNextOperationToReplay(changelog_iterator, &entry);
  1665. switch (rc)
  1666. {
  1667. case CL5_SUCCESS:
  1668. /* check that we don't return dummy entries */
  1669. if (is_dummy_operation (entry.op))
  1670. {
  1671. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1672. "%s: changelog iteration code returned a dummy entry with csn %s, "
  1673. "skipping ...\n",
  1674. agmt_get_long_name(prp->agmt), csn_as_string(entry.op->csn, PR_FALSE, csn_str));
  1675. continue;
  1676. }
  1677. replay_crc = replay_update(prp, entry.op, &message_id);
  1678. if (message_id)
  1679. {
  1680. rd->last_message_id_sent = message_id;
  1681. }
  1682. /* If we're talking to an old non-async replica, we need to pick up the response here */
  1683. if (CONN_OPERATION_SUCCESS != replay_crc)
  1684. {
  1685. int operation, error;
  1686. conn_get_error(prp->conn, &operation, &error);
  1687. csn_as_string(entry.op->csn, PR_FALSE, csn_str);
  1688. /* Figure out what to do next */
  1689. if (CONN_OPERATION_FAILED == replay_crc)
  1690. {
  1691. /* Map ldap error code to return value */
  1692. if (!ignore_error_and_keep_going(error))
  1693. {
  1694. return_value = UPDATE_TRANSIENT_ERROR;
  1695. finished = 1;
  1696. }
  1697. else
  1698. {
  1699. agmt_inc_last_update_changecount (prp->agmt, csn_get_replicaid(entry.op->csn), 1 /*skipped*/);
  1700. }
  1701. slapi_log_error(finished ? SLAPI_LOG_FATAL : slapi_log_urp, repl_plugin_name,
  1702. "%s: Failed to send update operation to consumer (uniqueid %s, CSN %s): %s. %s.\n",
  1703. agmt_get_long_name(prp->agmt),
  1704. entry.op->target_address.uniqueid, csn_str,
  1705. ldap_err2string(error),
  1706. finished ? "Will retry later" : "Skipping");
  1707. }
  1708. else if (CONN_NOT_CONNECTED == replay_crc)
  1709. {
  1710. /* We lost the connection - enter backoff state */
  1711. return_value = UPDATE_CONNECTION_LOST;
  1712. finished = 1;
  1713. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1714. "%s: Failed to send update operation to consumer (uniqueid %s, CSN %s): "
  1715. "%s. Will retry later.\n",
  1716. agmt_get_long_name(prp->agmt),
  1717. entry.op->target_address.uniqueid, csn_str,
  1718. error ? ldap_err2string(error) : "Connection lost");
  1719. }
  1720. else if (CONN_TIMEOUT == replay_crc)
  1721. {
  1722. return_value = UPDATE_TIMEOUT;
  1723. finished = 1;
  1724. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1725. "%s: Timed out sending update operation to consumer (uniqueid %s, CSN %s): "
  1726. "%s.\n",
  1727. agmt_get_long_name(prp->agmt),
  1728. entry.op->target_address.uniqueid, csn_str,
  1729. error ? ldap_err2string(error) : "Timeout");
  1730. }
  1731. else if (CONN_LOCAL_ERROR == replay_crc)
  1732. {
  1733. /*
  1734. * Something bad happened on the local server - enter
  1735. * backoff state.
  1736. */
  1737. return_value = UPDATE_TRANSIENT_ERROR;
  1738. finished = 1;
  1739. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1740. "%s: Failed to send update operation to consumer (uniqueid %s, CSN %s): "
  1741. "Local error. Will retry later.\n",
  1742. agmt_get_long_name(prp->agmt),
  1743. entry.op->target_address.uniqueid, csn_str);
  1744. }
  1745. }
  1746. else
  1747. {
  1748. char *uniqueid = NULL;
  1749. ReplicaId replica_id = 0;
  1750. csn_as_string(entry.op->csn, PR_FALSE, csn_str);
  1751. replica_id = csn_get_replicaid(entry.op->csn);
  1752. uniqueid = entry.op->target_address.uniqueid;
  1753. if (fractional_repl && message_id)
  1754. {
  1755. /* This update was sent no need to update the subentry
  1756. * and restart counting the skipped updates
  1757. */
  1758. subentry_update_needed = PR_FALSE;
  1759. skipped_updates = 0;
  1760. }
  1761. if (prp->repl50consumer && message_id)
  1762. {
  1763. int operation, error = 0;
  1764. conn_get_error(prp->conn, &operation, &error);
  1765. /* Get the response here */
  1766. replay_crc = repl5_inc_get_next_result(rd);
  1767. conn_get_error(prp->conn, &operation, &error);
  1768. csn_as_string(entry.op->csn, PR_FALSE, csn_str);
  1769. return_value = repl5_inc_update_from_op_result(prp, replay_crc, error, csn_str, uniqueid, replica_id, &finished, num_changes_sent);
  1770. }
  1771. else if (message_id) {
  1772. /* Queue the details for pickup later in the response thread */
  1773. repl5_inc_operation *sop = NULL;
  1774. sop = repl5_inc_operation_new();
  1775. PL_strncpyz(sop->csn_str, csn_str, sizeof(sop->csn_str));
  1776. sop->ldap_message_id = message_id;
  1777. sop->operation_type = entry.op->operation_type;
  1778. sop->replica_id = replica_id;
  1779. PL_strncpyz(sop->uniqueid, uniqueid, sizeof(sop->uniqueid));
  1780. repl5_int_push_operation(rd,sop);
  1781. repl5_inc_flow_control_results(prp->agmt, rd);
  1782. } else {
  1783. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1784. "%s: Skipping update operation with no message_id (uniqueid %s, CSN %s):\n",
  1785. agmt_get_long_name(prp->agmt),
  1786. entry.op->target_address.uniqueid, csn_str);
  1787. agmt_inc_last_update_changecount (prp->agmt, csn_get_replicaid(entry.op->csn), 1 /*skipped*/);
  1788. if (fractional_repl)
  1789. {
  1790. skipped_updates++;
  1791. if (skipped_updates > FRACTIONAL_SKIPPED_THRESHOLD) {
  1792. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1793. "%s: skipped updates is too high (%d) if no other update is sent we will update the subentry\n",
  1794. agmt_get_long_name(prp->agmt), skipped_updates);
  1795. subentry_update_needed = PR_TRUE;
  1796. }
  1797. }
  1798. }
  1799. }
  1800. break;
  1801. case CL5_BAD_DATA:
  1802. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1803. "%s: Invalid parameter passed to cl5GetNextOperationToReplay\n",
  1804. agmt_get_long_name(prp->agmt));
  1805. return_value = UPDATE_FATAL_ERROR;
  1806. finished = 1;
  1807. break;
  1808. case CL5_NOTFOUND:
  1809. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1810. "%s: No more updates to send (cl5GetNextOperationToReplay)\n",
  1811. agmt_get_long_name(prp->agmt));
  1812. return_value = UPDATE_NO_MORE_UPDATES;
  1813. finished = 1;
  1814. break;
  1815. case CL5_DB_ERROR:
  1816. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1817. "%s: A database error occurred (cl5GetNextOperationToReplay)\n",
  1818. agmt_get_long_name(prp->agmt));
  1819. return_value = UPDATE_FATAL_ERROR;
  1820. finished = 1;
  1821. break;
  1822. case CL5_BAD_FORMAT:
  1823. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1824. "%s: A malformed changelog entry was encountered (cl5GetNextOperationToReplay)\n",
  1825. agmt_get_long_name(prp->agmt));
  1826. break;
  1827. case CL5_MEMORY_ERROR:
  1828. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1829. "%s: A memory allocation error occurred (cl5GetNextOperationToRepla)\n",
  1830. agmt_get_long_name(prp->agmt));
  1831. return_value = UPDATE_FATAL_ERROR;
  1832. break;
  1833. case CL5_IGNORE_OP:
  1834. break;
  1835. default:
  1836. slapi_log_error(SLAPI_LOG_FATAL, repl_plugin_name,
  1837. "%s: Unknown error code (%d) returned from cl5GetNextOperationToReplay\n",
  1838. agmt_get_long_name(prp->agmt), rc);
  1839. return_value = UPDATE_TRANSIENT_ERROR;
  1840. break;
  1841. }
  1842. /* Check for protocol shutdown */
  1843. if (prp->terminate)
  1844. {
  1845. return_value = UPDATE_NO_MORE_UPDATES;
  1846. finished = 1;
  1847. }
  1848. if (*num_changes_sent >= MAX_CHANGES_PER_SESSION)
  1849. {
  1850. return_value = UPDATE_YIELD;
  1851. finished = 1;
  1852. }
  1853. PR_Lock(rd->lock);
  1854. /* See if the result thread has hit a problem */
  1855. if(!finished && rd->abort_time){
  1856. time_t current_time = time ( NULL );
  1857. if ((current_time - rd->abort_time) >= release_timeout){
  1858. rd->result = UPDATE_YIELD;
  1859. return_value = UPDATE_YIELD;
  1860. finished = 1;
  1861. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1862. "Aborting send_updates...(%s)\n",
  1863. agmt_get_long_name(rd->prp->agmt));
  1864. }
  1865. }
  1866. if (!finished && rd->abort == ABORT_SESSION)
  1867. {
  1868. return_value = rd->result;
  1869. finished = 1;
  1870. }
  1871. PR_Unlock(rd->lock);
  1872. } while (!finished);
  1873. if (fractional_repl && subentry_update_needed)
  1874. {
  1875. ReplicaId rid = -1; /* Used to create the replica keep alive subentry */
  1876. replica = (Replica*) object_get_data(prp->replica_object);
  1877. if (replica)
  1878. {
  1879. rid = replica_get_rid(replica);
  1880. }
  1881. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1882. "%s: skipped updates was definitely too high (%d) update the subentry now\n",
  1883. agmt_get_long_name(prp->agmt), skipped_updates);
  1884. replica_subentry_update(agmt_get_replarea(prp->agmt), rid);
  1885. }
  1886. /* Terminate the results reading thread */
  1887. if (!prp->repl50consumer)
  1888. {
  1889. /* We need to ensure that we wait until all the responses have been received from our operations */
  1890. if (return_value != UPDATE_CONNECTION_LOST) {
  1891. /*
  1892. * If we already have an error, there is no need to check the
  1893. * async result thread anymore.
  1894. */
  1895. if (return_value == UPDATE_NO_MORE_UPDATES || return_value == UPDATE_YIELD)
  1896. {
  1897. /*
  1898. * We need to double check that an error hasn't popped up from
  1899. * the async result thread since our last check.
  1900. */
  1901. int final_result;
  1902. if((final_result = repl5_inc_waitfor_async_results(rd))){
  1903. return_value = final_result;
  1904. }
  1905. }
  1906. }
  1907. rc = repl5_inc_destroy_async_result_thread(rd);
  1908. if (rc) {
  1909. slapi_log_error (SLAPI_LOG_FATAL, repl_plugin_name, "%s: repl5_inc_run: "
  1910. "repl5_tot_destroy_async_result_thread failed; error - %d\n",
  1911. agmt_get_long_name(prp->agmt), rc);
  1912. }
  1913. *num_changes_sent = rd->num_changes_sent;
  1914. }
  1915. PR_Lock(rd->lock);
  1916. if (rd->flowcontrol_detection) {
  1917. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1918. "%s: Incremental update flow control triggered %d times\n"
  1919. "You may increase %s and/or decrease %s in the replica agreement configuration\n",
  1920. agmt_get_long_name(prp->agmt),
  1921. rd->flowcontrol_detection,
  1922. type_nsds5ReplicaFlowControlPause,
  1923. type_nsds5ReplicaFlowControlWindow);
  1924. }
  1925. PR_Unlock(rd->lock);
  1926. repl5_inc_rd_destroy(&rd);
  1927. cl5_operation_parameters_done ( entry.op );
  1928. cl5DestroyReplayIterator(&changelog_iterator);
  1929. }
  1930. return return_value;
  1931. }
  1932. /*
  1933. * XXXggood this should probably be in the superclass, since the full update
  1934. * protocol is going to need it too.
  1935. */
  1936. static int
  1937. repl5_inc_stop(Private_Repl_Protocol *prp)
  1938. {
  1939. int return_value;
  1940. PRIntervalTime start, maxwait, now;
  1941. int seconds = 1200;
  1942. maxwait = PR_SecondsToInterval(seconds);
  1943. prp->terminate = 1;
  1944. event_notify(prp, EVENT_PROTOCOL_SHUTDOWN);
  1945. start = PR_IntervalNow();
  1946. now = start;
  1947. while (!prp->stopped && ((now - start) < maxwait))
  1948. {
  1949. DS_Sleep(PR_MillisecondsToInterval(100));
  1950. now = PR_IntervalNow();
  1951. }
  1952. if (!prp->stopped)
  1953. {
  1954. /* Isn't listening. Do something drastic. */
  1955. return_value = -1;
  1956. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1957. "%s: repl5_inc_stop: protocol does not stop after %d seconds\n",
  1958. agmt_get_long_name(prp->agmt), seconds);
  1959. }
  1960. else
  1961. {
  1962. return_value = 0;
  1963. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1964. "%s: repl5_inc_stop: protocol stopped after %d seconds\n",
  1965. agmt_get_long_name(prp->agmt),
  1966. PR_IntervalToSeconds(now-start));
  1967. }
  1968. if (slapi_is_loglevel_set(SLAPI_LOG_REPL)) {
  1969. if (NULL == prp->replica_object) {
  1970. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1971. "%s: repl5_inc_stop: protocol replica_object is NULL\n",
  1972. agmt_get_long_name(prp->agmt));
  1973. } else {
  1974. Replica *replica;
  1975. object_acquire(prp->replica_object);
  1976. replica = object_get_data(prp->replica_object);
  1977. if (NULL == replica) {
  1978. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1979. "%s: repl5_inc_stop: replica is NULL\n",
  1980. agmt_get_long_name(prp->agmt));
  1981. } else {
  1982. Object *ruv_obj = replica_get_ruv(replica);
  1983. if (NULL == ruv_obj) {
  1984. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1985. "%s: repl5_inc_stop: ruv_obj is NULL\n",
  1986. agmt_get_long_name(prp->agmt));
  1987. } else {
  1988. RUV *ruv;
  1989. object_acquire(ruv_obj);
  1990. ruv = (RUV*)object_get_data (ruv_obj);
  1991. if (NULL == ruv) {
  1992. slapi_log_error(SLAPI_LOG_REPL, repl_plugin_name,
  1993. "%s: repl5_inc_stop: ruv is NULL\n",
  1994. agmt_get_long_name(prp->agmt));
  1995. } else {
  1996. ruv_dump(ruv, "Database RUV", NULL);
  1997. }
  1998. object_release(ruv_obj);
  1999. }
  2000. }
  2001. object_release(prp->replica_object);
  2002. }
  2003. }
  2004. return return_value;
  2005. }
  2006. static int
  2007. repl5_inc_status(Private_Repl_Protocol *prp)
  2008. {
  2009. int return_value = 0;
  2010. return return_value;
  2011. }
  2012. static void
  2013. repl5_inc_notify_update(Private_Repl_Protocol *prp)
  2014. {
  2015. event_notify(prp, EVENT_TRIGGERING_CRITERIA_MET);
  2016. }
  2017. static void
  2018. repl5_inc_update_now(Private_Repl_Protocol *prp)
  2019. {
  2020. event_notify(prp, EVENT_REPLICATE_NOW);
  2021. }
  2022. static void
  2023. repl5_inc_notify_agmt_changed(Private_Repl_Protocol *prp)
  2024. {
  2025. event_notify(prp, EVENT_AGMT_CHANGED);
  2026. }
  2027. static void
  2028. repl5_inc_notify_window_opened (Private_Repl_Protocol *prp)
  2029. {
  2030. event_notify(prp, EVENT_WINDOW_OPENED);
  2031. }
  2032. static void
  2033. repl5_inc_notify_window_closed (Private_Repl_Protocol *prp)
  2034. {
  2035. event_notify(prp, EVENT_WINDOW_CLOSED);
  2036. }
  2037. Private_Repl_Protocol *
  2038. Repl_5_Inc_Protocol_new(Repl_Protocol *rp)
  2039. {
  2040. repl5_inc_private *rip = NULL;
  2041. Private_Repl_Protocol *prp = (Private_Repl_Protocol *)slapi_ch_malloc(sizeof(Private_Repl_Protocol));
  2042. prp->delete = repl5_inc_delete;
  2043. prp->run = repl5_inc_run;
  2044. prp->stop = repl5_inc_stop;
  2045. prp->status = repl5_inc_status;
  2046. prp->notify_update = repl5_inc_notify_update;
  2047. prp->notify_agmt_changed = repl5_inc_notify_agmt_changed;
  2048. prp->notify_window_opened = repl5_inc_notify_window_opened;
  2049. prp->notify_window_closed = repl5_inc_notify_window_closed;
  2050. prp->update_now = repl5_inc_update_now;
  2051. prp->replica_object = prot_get_replica_object(rp);
  2052. if ((prp->lock = PR_NewLock()) == NULL)
  2053. {
  2054. goto loser;
  2055. }
  2056. if ((prp->cvar = PR_NewCondVar(prp->lock)) == NULL)
  2057. {
  2058. goto loser;
  2059. }
  2060. prp->stopped = 0;
  2061. prp->terminate = 0;
  2062. prp->eventbits = 0;
  2063. prp->conn = prot_get_connection(rp);
  2064. prp->agmt = prot_get_agreement(rp);
  2065. prp->last_acquire_response_code = NSDS50_REPL_REPLICA_READY;
  2066. rip = (void *)slapi_ch_malloc(sizeof(repl5_inc_private));
  2067. rip->ruv = NULL;
  2068. rip->backoff = NULL;
  2069. rip->rp = rp;
  2070. prp->private = (void *)rip;
  2071. prp->replica_acquired = PR_FALSE;
  2072. prp->repl50consumer = 0;
  2073. prp->repl71consumer = 0;
  2074. prp->repl90consumer = 0;
  2075. return prp;
  2076. loser:
  2077. repl5_inc_delete(&prp);
  2078. return NULL;
  2079. }
  2080. static void
  2081. repl5_inc_backoff_expired(time_t timer_fire_time, void *arg)
  2082. {
  2083. Private_Repl_Protocol *prp = (Private_Repl_Protocol *)arg;
  2084. PR_ASSERT(NULL != prp);
  2085. event_notify(prp, EVENT_BACKOFF_EXPIRED);
  2086. }
  2087. /*
  2088. * Examine the update vector and determine our course of action.
  2089. * There are 3 different possibilities, plus a catch-all error:
  2090. * 1 - no update vector (ruv is NULL). The consumer's replica is
  2091. * pristine, so it needs to be initialized. Return
  2092. * EXAMINE_RUV_PRISTINE_REPLICA.
  2093. * 2 - ruv is present, but its database generation ID doesn't
  2094. * match the local generation ID. This means that either
  2095. * the local replica must be reinitialized from the remote
  2096. * replica or vice-versa. Return
  2097. * EXAMINE_RUV_GENERATION_MISMATCH.
  2098. * 3 - ruv is present, and we have all updates needed to bring
  2099. * the replica up to date using the incremental protocol.
  2100. * return EXAMINE_RUV_OK.
  2101. * 4 - parameter error. Return EXAMINE_RUV_PARAM_ERROR
  2102. */
  2103. static int
  2104. examine_update_vector(Private_Repl_Protocol *prp, RUV *remote_ruv)
  2105. {
  2106. int return_value;
  2107. PR_ASSERT(NULL != prp);
  2108. if (NULL == prp)
  2109. {
  2110. return_value = EXAMINE_RUV_PARAM_ERROR;
  2111. }
  2112. else if (NULL == remote_ruv)
  2113. {
  2114. return_value = EXAMINE_RUV_PRISTINE_REPLICA;
  2115. }
  2116. else
  2117. {
  2118. char *local_gen = NULL;
  2119. char *remote_gen = ruv_get_replica_generation(remote_ruv);
  2120. Object *local_ruv_obj;
  2121. RUV *local_ruv;
  2122. Replica *replica;
  2123. PR_ASSERT(NULL != prp->replica_object);
  2124. replica = object_get_data(prp->replica_object);
  2125. PR_ASSERT(NULL != replica);
  2126. local_ruv_obj = replica_get_ruv (replica);
  2127. if (NULL != local_ruv_obj)
  2128. {
  2129. local_ruv = (RUV*)object_get_data (local_ruv_obj);
  2130. PR_ASSERT (local_ruv);
  2131. local_gen = ruv_get_replica_generation(local_ruv);
  2132. object_release (local_ruv_obj);
  2133. }
  2134. if (NULL == remote_gen || NULL == local_gen || strcmp(remote_gen, local_gen) != 0)
  2135. {
  2136. return_value = EXAMINE_RUV_GENERATION_MISMATCH;
  2137. }
  2138. else
  2139. {
  2140. return_value = EXAMINE_RUV_OK;
  2141. }
  2142. slapi_ch_free((void**)&remote_gen);
  2143. slapi_ch_free((void**)&local_gen);
  2144. }
  2145. return return_value;
  2146. }
  2147. /*
  2148. * When we get an error from an LDAP operation, we call this
  2149. * function to decide if we should just keep replaying
  2150. * updates, or if we should stop, back off, and try again
  2151. * later.
  2152. * Returns PR_TRUE if we shoould keep going, PR_FALSE if
  2153. * we should back off and try again later.
  2154. *
  2155. * In general, we keep going if the return code is consistent
  2156. * with some sort of bug in URP that causes the consumer to
  2157. * emit an error code that it shouldn't have, e.g. LDAP_ALREADY_EXISTS.
  2158. *
  2159. * We stop if there's some indication that the server just completely
  2160. * failed to process the operation, e.g. LDAP_OPERATIONS_ERROR.
  2161. */
  2162. PRBool
  2163. ignore_error_and_keep_going(int error)
  2164. {
  2165. int return_value = PR_FALSE;
  2166. switch (error)
  2167. {
  2168. /* Cases where we keep going */
  2169. case LDAP_SUCCESS:
  2170. case LDAP_NO_SUCH_ATTRIBUTE:
  2171. case LDAP_UNDEFINED_TYPE:
  2172. case LDAP_CONSTRAINT_VIOLATION:
  2173. case LDAP_TYPE_OR_VALUE_EXISTS:
  2174. case LDAP_INVALID_SYNTAX:
  2175. case LDAP_NO_SUCH_OBJECT:
  2176. case LDAP_INVALID_DN_SYNTAX:
  2177. case LDAP_IS_LEAF:
  2178. case LDAP_INSUFFICIENT_ACCESS:
  2179. case LDAP_NAMING_VIOLATION:
  2180. case LDAP_OBJECT_CLASS_VIOLATION:
  2181. case LDAP_NOT_ALLOWED_ON_NONLEAF:
  2182. case LDAP_NOT_ALLOWED_ON_RDN:
  2183. case LDAP_ALREADY_EXISTS:
  2184. case LDAP_NO_OBJECT_CLASS_MODS:
  2185. return_value = PR_TRUE;
  2186. break;
  2187. /* Cases where we stop and retry */
  2188. case LDAP_OPERATIONS_ERROR:
  2189. case LDAP_PROTOCOL_ERROR:
  2190. case LDAP_TIMELIMIT_EXCEEDED:
  2191. case LDAP_SIZELIMIT_EXCEEDED:
  2192. case LDAP_STRONG_AUTH_NOT_SUPPORTED:
  2193. case LDAP_STRONG_AUTH_REQUIRED:
  2194. case LDAP_PARTIAL_RESULTS:
  2195. case LDAP_REFERRAL:
  2196. case LDAP_ADMINLIMIT_EXCEEDED:
  2197. case LDAP_UNAVAILABLE_CRITICAL_EXTENSION:
  2198. case LDAP_CONFIDENTIALITY_REQUIRED:
  2199. case LDAP_SASL_BIND_IN_PROGRESS:
  2200. case LDAP_INAPPROPRIATE_MATCHING:
  2201. case LDAP_ALIAS_PROBLEM:
  2202. case LDAP_ALIAS_DEREF_PROBLEM:
  2203. case LDAP_INAPPROPRIATE_AUTH:
  2204. case LDAP_INVALID_CREDENTIALS:
  2205. case LDAP_BUSY:
  2206. case LDAP_UNAVAILABLE:
  2207. case LDAP_UNWILLING_TO_PERFORM:
  2208. case LDAP_LOOP_DETECT:
  2209. case LDAP_SORT_CONTROL_MISSING:
  2210. case LDAP_INDEX_RANGE_ERROR:
  2211. case LDAP_RESULTS_TOO_LARGE:
  2212. case LDAP_AFFECTS_MULTIPLE_DSAS:
  2213. case LDAP_OTHER:
  2214. case LDAP_SERVER_DOWN:
  2215. case LDAP_LOCAL_ERROR:
  2216. case LDAP_ENCODING_ERROR:
  2217. case LDAP_DECODING_ERROR:
  2218. case LDAP_TIMEOUT:
  2219. case LDAP_AUTH_UNKNOWN:
  2220. case LDAP_FILTER_ERROR:
  2221. case LDAP_USER_CANCELLED:
  2222. case LDAP_PARAM_ERROR:
  2223. case LDAP_NO_MEMORY:
  2224. case LDAP_CONNECT_ERROR:
  2225. case LDAP_NOT_SUPPORTED:
  2226. case LDAP_CONTROL_NOT_FOUND:
  2227. case LDAP_NO_RESULTS_RETURNED:
  2228. case LDAP_MORE_RESULTS_TO_RETURN:
  2229. case LDAP_CLIENT_LOOP:
  2230. case LDAP_REFERRAL_LIMIT_EXCEEDED:
  2231. return_value = PR_FALSE;
  2232. break;
  2233. }
  2234. return return_value;
  2235. }
  2236. /* this function converts a state to its name - for debug output */
  2237. static const char*
  2238. state2name (int state)
  2239. {
  2240. switch (state)
  2241. {
  2242. case STATE_START: return "start";
  2243. case STATE_WAIT_WINDOW_OPEN: return "wait_for_window_to_open";
  2244. case STATE_WAIT_CHANGES: return "wait_for_changes";
  2245. case STATE_READY_TO_ACQUIRE: return "ready_to_acquire_replica";
  2246. case STATE_BACKOFF_START: return "start_backoff";
  2247. case STATE_BACKOFF: return "backoff";
  2248. case STATE_SENDING_UPDATES: return "sending_updates";
  2249. case STATE_STOP_FATAL_ERROR: return "stop_fatal_error";
  2250. case STATE_STOP_FATAL_ERROR_PART2: return "stop_fatal_error";
  2251. case STATE_STOP_NORMAL_TERMINATION: return "stop_normal_termination";
  2252. default: return "invalid_state";
  2253. }
  2254. }
  2255. /* this function convert s an event to its name - for debug output */
  2256. static const char*
  2257. event2name (int event)
  2258. {
  2259. switch (event)
  2260. {
  2261. case EVENT_WINDOW_OPENED: return "update_window_opened";
  2262. case EVENT_WINDOW_CLOSED: return "update_window_closed";
  2263. case EVENT_TRIGGERING_CRITERIA_MET: return "data_modified";
  2264. case EVENT_BACKOFF_EXPIRED: return "backoff_timer_expired";
  2265. case EVENT_REPLICATE_NOW: return "replicate_now";
  2266. case EVENT_PROTOCOL_SHUTDOWN: return "protocol_shutdown";
  2267. case EVENT_AGMT_CHANGED: return "agreement_changed";
  2268. default: return "invalid_event";
  2269. }
  2270. }
  2271. static const char*
  2272. op2string(int op)
  2273. {
  2274. switch (op) {
  2275. case SLAPI_OPERATION_ADD:
  2276. return "add";
  2277. case SLAPI_OPERATION_MODIFY:
  2278. return "modify";
  2279. case SLAPI_OPERATION_DELETE:
  2280. return "delete";
  2281. case SLAPI_OPERATION_MODRDN:
  2282. return "rename";
  2283. case SLAPI_OPERATION_EXTENDED:
  2284. return "extended";
  2285. }
  2286. return "unknown";
  2287. }