Subtle changes to message handling after ENUMJOBS.

Jeremy.
(This used to be commit 48f3bf0ea51b9fd09dfb017870e32ca4a8cc4b8c)

3 files changed, 183 insertions, 19 deletions

diff --git a/source3/printing/notify.c b/source3/printing/notify.c
index 50c5ce39f6..641f951bdd 100644
--- a/source3/printing/notify.c
+++ b/source3/printing/notify.c
@@ -27,6 +27,7 @@ static TALLOC_CTX *send_ctx;
 static struct notify_queue {
 	struct notify_queue *next, *prev;
 	struct spoolss_notify_msg *msg;
+	struct timeval tv;
 	char *buf;
 	size_t buflen;
 } *notify_queue_head = NULL;
@@ -81,7 +82,8 @@ again:
 
 	len += tdb_pack(buf + len, buflen - len, "f", msg->printer);
 
-	len += tdb_pack(buf + len, buflen - len, "ddddd",
+	len += tdb_pack(buf + len, buflen - len, "ddddddd",
+			(uint32)q->tv.tv_sec, (uint32)q->tv.tv_usec,
 			msg->type, msg->field, msg->id, msg->len, msg->flags);
 
 	/* Pack data */
@@ -259,6 +261,7 @@ in notify_queue\n", msg->type, msg->field, msg->printer));
 		return;
 	}
 	copy_notify2_msg(pnqueue->msg, msg);
+	gettimeofday(&pnqueue->tv, NULL);
 	pnqueue->buf = NULL;
 	pnqueue->buflen = 0;
 
diff --git a/source3/printing/printing.c b/source3/printing/printing.c
index cff6eb62ef..06941c67dd 100644
--- a/source3/printing/printing.c
+++ b/source3/printing/printing.c
@@ -24,6 +24,7 @@
 
 /* Current printer interface */
 static struct printif *current_printif = &generic_printif;
+static BOOL remove_from_jobs_changed(int snum, uint32 jobid);
 
 /* 
    the printing backend revolves around a tdb database that stores the
@@ -663,9 +664,11 @@ static int traverse_fn_delete(TDB_CONTEXT *t, TDB_DATA key, TDB_DATA data, void
 			if (jobid == u_jobid)
 				break;
 		}
-		if (i == ts->qcount)
+		if (i == ts->qcount) {
+			DEBUG(10,("traverse_fn_delete: pjob %u deleted due to !smbjob\n",
+						(unsigned int)jobid ));
 			pjob_delete(ts->snum, jobid);
-		else
+		} else
 			ts->total_jobs++;
 		return 0;
 	}
@@ -675,9 +678,11 @@ static int traverse_fn_delete(TDB_CONTEXT *t, TDB_DATA key, TDB_DATA data, void
 		/* if a job is not spooled and the process doesn't
                    exist then kill it. This cleans up after smbd
                    deaths */
-		if (!process_exists(pjob.pid))
+		if (!process_exists(pjob.pid)) {
+			DEBUG(10,("traverse_fn_delete: pjob %u deleted due to !process_exists (%u)\n",
+						(unsigned int)jobid, (unsigned int)pjob.pid ));
 			pjob_delete(ts->snum, jobid);
-		else
+		} else
 			ts->total_jobs++;
 		return 0;
 	}
@@ -700,9 +705,13 @@ static int traverse_fn_delete(TDB_CONTEXT *t, TDB_DATA key, TDB_DATA data, void
 		   is currently traversing the printing tdb and deleting jobs.
 		   Don't delete the job if it was submitted after the lpq_time. */
 
-		if (pjob.starttime < ts->lpq_time)
+		if (pjob.starttime < ts->lpq_time) {
+			DEBUG(10,("traverse_fn_delete: pjob %u deleted due to pjob.starttime (%u) < ts->lpq_time (%u)\n",
+						(unsigned int)jobid,
+						(unsigned int)pjob.starttime,
+						(unsigned int)ts->lpq_time ));
 			pjob_delete(ts->snum, jobid);
-		else
+		} else
 			ts->total_jobs++;
 	}
 	else
@@ -872,6 +881,37 @@ static void store_queue_struct(struct tdb_print_db *pdb, struct traverse_struct
 	return;
 }
 
+static TDB_DATA get_jobs_changed_data(struct tdb_print_db *pdb)
+{
+	TDB_DATA data, key;
+
+	key.dptr = "INFO/jobs_changed";
+	key.dsize = strlen(key.dptr);
+	ZERO_STRUCT(data);
+
+	data = tdb_fetch(pdb->tdb, key);
+	if (data.dptr == NULL || data.dsize == 0 || (data.dsize % 4 != 0)) {
+		SAFE_FREE(data.dptr);
+		ZERO_STRUCT(data);
+	}
+
+	return data;
+}
+
+static void check_job_changed(int snum, TDB_DATA data, uint32 jobid)
+{
+	unsigned int i;
+	unsigned int job_count = data.dsize / 4;
+
+	for (i = 0; i < job_count; i++) {
+		uint32 ch_jobid;
+
+		memcpy(&ch_jobid, data.dptr + (i*4), 4);
+		if (ch_jobid == jobid)
+			remove_from_jobs_changed(snum, jobid);
+	}
+}
+
 /****************************************************************************
  Update the internal database from the system print queue for a queue.
 ****************************************************************************/
@@ -886,6 +926,7 @@ static void print_queue_update(int snum)
 	struct traverse_struct tstruct;
 	fstring keystr, printer_name, cachestr;
 	TDB_DATA data, key;
+	TDB_DATA jcdata;
 	struct tdb_print_db *pdb;
 
 	fstrcpy(printer_name, lp_const_servicename(snum));
@@ -975,6 +1016,9 @@ static void print_queue_update(int snum)
 
 	  fill in any system job numbers as we go
 	*/
+
+	jcdata = get_jobs_changed_data(pdb);
+
 	for (i=0; i<qcount; i++) {
 		uint32 jobid = print_parse_jobid(queue[i].fs_file);
 
@@ -996,10 +1040,12 @@ static void print_queue_update(int snum)
 
 		pjob->sysjob = queue[i].job;
 		pjob->status = queue[i].status;
-
 		pjob_store(snum, jobid, pjob);
+		check_job_changed(snum, jcdata, jobid);
 	}
 
+	SAFE_FREE(jcdata.dptr);
+
 	/* now delete any queued entries that don't appear in the
            system queue */
 	tstruct.queue = queue;
@@ -1364,6 +1410,10 @@ static BOOL remove_from_jobs_changed(int snum, uint32 jobid)
 		tdb_chainunlock(pdb->tdb, key);
 	SAFE_FREE(data.dptr);
 	release_print_db(pdb);
+	if (ret)
+		DEBUG(10,("remove_from_jobs_changed: removed jobid %u\n", (unsigned int)jobid ));
+	else
+		DEBUG(10,("remove_from_jobs_changed: Failed to remove jobid %u\n", (unsigned int)jobid ));
 	return ret;
 }
 
@@ -1406,8 +1456,18 @@ static BOOL print_job_delete1(int snum, uint32 jobid)
 	/* Delete the tdb entry if the delete suceeded or the job hasn't
 	   been spooled. */
 
-	if (result == 0)
+	if (result == 0) {
+		const char *printername = lp_const_servicename(snum);
+		struct tdb_print_db *pdb = get_print_db_byname(printername);
+		int njobs = 1;
+
+		if (!pdb)
+			return False;
 		pjob_delete(snum, jobid);
+		/* Ensure we keep a rough count of the number of total jobs... */
+		tdb_change_int32_atomic(pdb->tdb, "INFO/total_jobs", &njobs, -1);
+		release_print_db(pdb);
+	}
 
 	return (result == 0);
 }
@@ -1790,6 +1850,8 @@ static BOOL add_to_jobs_changed(struct tdb_print_db *pdb, uint32 jobid)
 	data.dptr = (char *)&jobid;
 	data.dsize = 4;
 
+	DEBUG(10,("add_to_jobs_changed: Added jobid %u\n", (unsigned int)jobid ));
+
 	return (tdb_append(pdb->tdb, key, data) == 0);
 }
 
@@ -1998,7 +2060,6 @@ BOOL print_job_end(int snum, uint32 jobid, BOOL normal_close)
 	pjob->spooled = True;
 	pjob->status = LPQ_QUEUED;
 	pjob_store(snum, jobid, pjob);
-	remove_from_jobs_changed(snum, jobid);
 	
 	/* make sure the database is up to date */
 	if (print_cache_expired(snum))
@@ -2031,6 +2092,10 @@ static BOOL get_stored_queue_info(struct tdb_print_db *pdb, int snum, int *pcoun
 	int max_reported_jobs = lp_max_reported_jobs(snum);
 	BOOL ret = False;
 
+	/* make sure the database is up to date */
+	if (print_cache_expired(snum))
+		print_queue_update(snum);
+ 
 	*pcount = 0;
 	*ppqueue = NULL;
 
@@ -2055,6 +2120,8 @@ static BOOL get_stored_queue_info(struct tdb_print_db *pdb, int snum, int *pcoun
 	if (cgdata.dptr != NULL && (cgdata.dsize % 4 == 0))
 		extra_count = cgdata.dsize/4;
 
+	DEBUG(5,("get_stored_queue_info: qcount = %u, extra_count = %u\n", (unsigned int)qcount, (unsigned int)extra_count));
+
 	/* Allocate the queue size. */
 	if (qcount == 0 && extra_count == 0)
 		goto out;
@@ -2091,9 +2158,13 @@ static BOOL get_stored_queue_info(struct tdb_print_db *pdb, int snum, int *pcoun
 		struct printjob *pjob;
 
 		memcpy(&jobid, &cgdata.dptr[i*4], 4);
+		DEBUG(5,("get_stored_queue_info: changed job = %u\n", (unsigned int)jobid));
 		pjob = print_job_find(snum, jobid);
-		if (!pjob)
+		if (!pjob) {
+			DEBUG(5,("get_stored_queue_info: failed to find changed job = %u\n", (unsigned int)jobid));
+			remove_from_jobs_changed(snum, jobid);
 			continue;
+		}
 
 		queue[total_count].job = jobid;
 		queue[total_count].size = pjob->size;
@@ -2102,6 +2173,7 @@ static BOOL get_stored_queue_info(struct tdb_print_db *pdb, int snum, int *pcoun
 		queue[total_count].priority = 1;
 		fstrcpy(queue[total_count].fs_user, pjob->user);
 		fstrcpy(queue[total_count].fs_file, pjob->jobname);
+		total_count++;
 	}
 
 	/* Sort the queue by submission time otherwise they are displayed
@@ -2109,6 +2181,8 @@ static BOOL get_stored_queue_info(struct tdb_print_db *pdb, int snum, int *pcoun
 
 	qsort(queue, total_count, sizeof(print_queue_struct), QSORT_CAST(printjob_comp));
 
+	DEBUG(5,("get_stored_queue_info: total_count = %u\n", (unsigned int)total_count));
+
 	if (max_reported_jobs && total_count > max_reported_jobs)
 		total_count = max_reported_jobs;
 
diff --git a/source3/rpc_server/srv_spoolss_nt.c b/source3/rpc_server/srv_spoolss_nt.c
index c2729001e4..71d7530410 100644
--- a/source3/rpc_server/srv_spoolss_nt.c
+++ b/source3/rpc_server/srv_spoolss_nt.c
@@ -1031,9 +1031,10 @@ done:
 /***********************************************************************
  **********************************************************************/
 
-static BOOL notify2_unpack_msg( SPOOLSS_NOTIFY_MSG *msg, void *buf, size_t len )
+static BOOL notify2_unpack_msg( SPOOLSS_NOTIFY_MSG *msg, struct timeval *tv, void *buf, size_t len )
 {
 
+	uint32 tv_sec, tv_usec;
 	size_t offset = 0;
 
 	/* Unpack message */
@@ -1041,8 +1042,9 @@ static BOOL notify2_unpack_msg( SPOOLSS_NOTIFY_MSG *msg, void *buf, size_t len )
 	offset += tdb_unpack((char *)buf + offset, len - offset, "f",
 			     msg->printer);
 	
-	offset += tdb_unpack((char *)buf + offset, len - offset, "ddddd",
-			     &msg->type, &msg->field, &msg->id, &msg->len, &msg->flags);
+	offset += tdb_unpack((char *)buf + offset, len - offset, "ddddddd",
+				&tv_sec, &tv_usec,
+				&msg->type, &msg->field, &msg->id, &msg->len, &msg->flags);
 
 	if (msg->len == 0)
 		tdb_unpack((char *)buf + offset, len - offset, "dd",
@@ -1054,6 +1056,9 @@ static BOOL notify2_unpack_msg( SPOOLSS_NOTIFY_MSG *msg, void *buf, size_t len )
 	DEBUG(3, ("notify2_unpack_msg: got NOTIFY2 message, type %d, field 0x%02x, flags 0x%04x\n",
 		  msg->type, msg->field, msg->flags));
 
+	tv->tv_sec = tv_sec;
+	tv->tv_usec = tv_usec;
+
 	if (msg->len == 0)
 		DEBUG(3, ("notify2_unpack_msg: value1 = %d, value2 = %d\n", msg->notify.value[0],
 			  msg->notify.value[1]));
@@ -1063,6 +1068,58 @@ static BOOL notify2_unpack_msg( SPOOLSS_NOTIFY_MSG *msg, void *buf, size_t len )
 	return True;
 }
 
+/* ENUMJOB last timestamp list. */
+struct ejts_list {
+	struct ejts_list *next, *prev;
+	char *printer_name;
+	struct timeval tv;
+};
+
+static struct ejts_list *ejts_head;
+
+static struct ejts_list *find_enumjobs_timestamp(const char *printer_name)
+{
+	struct ejts_list *ejtsl;
+
+	for( ejtsl = ejts_head; ejtsl; ejtsl = ejtsl->next)
+		if (strequal(ejtsl->printer_name, printer_name))
+			return ejtsl;
+	return NULL;
+}
+
+static void set_enumjobs_timestamp(int snum)
+{
+	const char *printer_name = lp_const_servicename(snum);
+	struct ejts_list *ejtsl = find_enumjobs_timestamp(printer_name);
+
+	if (!ejtsl) {
+		ejtsl = (struct ejts_list *)malloc(sizeof(struct ejts_list));
+		if (!ejtsl)
+			return;
+		ejtsl->printer_name = strdup(printer_name);
+		if (!ejtsl->printer_name) {
+			SAFE_FREE(ejtsl);
+			return;
+		}
+		DLIST_ADD(ejts_head, ejtsl);
+	}
+
+	gettimeofday(&ejtsl->tv, NULL);
+}
+
+static int timeval_diff(struct timeval *tv1, struct timeval *tv2)
+{
+	if (tv1->tv_sec > tv2->tv_sec)
+		return 1;
+	if (tv1->tv_sec < tv2->tv_sec)
+		return -1;
+	if (tv1->tv_usec > tv2->tv_usec)
+		return 1;
+	if (tv1->tv_usec < tv2->tv_usec)
+		return -1;
+	return 0;
+}
+
 /********************************************************************
  Receive a notify2 message list
  ********************************************************************/
@@ -1104,8 +1161,9 @@ static void receive_notify2_message_list(int msg_type, pid_t src, void *msg, siz
 	 * call.  Therefore messages are grouped according to printer handle.
 	 */
 	 
-	for ( i=0; i<msg_count; i++ ) 
-	{
+	for ( i=0; i<msg_count; i++ ) {
+		struct timeval msg_tv;
+
 		if (msg_ptr + 4 - buf > len) {
 			DEBUG(0,("receive_notify2_message_list: bad message format (len > buf_size) !\n"));
 			return;
@@ -1122,9 +1180,32 @@ static void receive_notify2_message_list(int msg_type, pid_t src, void *msg, siz
 		/* unpack messages */
 		
 		ZERO_STRUCT( notify );
-		notify2_unpack_msg( &notify, msg_ptr, msg_len );
+		notify2_unpack_msg( &notify, &msg_tv, msg_ptr, msg_len );
 		msg_ptr += msg_len;
 		
+		/* See if it is still relevent. */
+		if (notify.type == JOB_NOTIFY_TYPE) {
+			BOOL status_is_deleting = False;
+
+			if (notify.field == JOB_NOTIFY_STATUS && (notify.notify.value[0] & (JOB_STATUS_DELETING|JOB_STATUS_DELETED)))
+				status_is_deleting = True;
+
+			if (!status_is_deleting) {
+				struct ejts_list *ejtsl = find_enumjobs_timestamp(notify.printer);
+
+				if (ejtsl && (timeval_diff(&ejtsl->tv, &msg_tv) > 0)) {
+
+					DEBUG(10, ("receive_notify2_message_list: enumjobs ts = %u, %u, msg ts = %u, %u discarding\n",
+						(unsigned int)ejtsl->tv.tv_sec, (unsigned int)ejtsl->tv.tv_usec,
+						(unsigned int)msg_tv.tv_sec, (unsigned int)msg_tv.tv_usec ));
+
+					/* Message no longer relevent. Ignore it. */
+					if ( notify.len != 0 )
+						SAFE_FREE( notify.notify.data );
+					continue;
+				}
+			}
+		}
 		/* add to correct list in container */
 		
 		notify_msg_ctr_addmsg( &messages, &notify );
@@ -6352,6 +6433,7 @@ WERROR _spoolss_enumjobs( pipes_struct *p, SPOOL_Q_ENUMJOBS *q_u, SPOOL_R_ENUMJO
 	uint32 offered = q_u->offered;
 	uint32 *needed = &r_u->needed;
 	uint32 *returned = &r_u->returned;
+	WERROR wret;
 
 	int snum;
 	print_status_struct prt_status;
@@ -6373,15 +6455,20 @@ WERROR _spoolss_enumjobs( pipes_struct *p, SPOOL_Q_ENUMJOBS *q_u, SPOOL_R_ENUMJO
 	DEBUGADD(4,("count:[%d], status:[%d], [%s]\n", *returned, prt_status.status, prt_status.message));
 
 	if (*returned == 0) {
+		set_enumjobs_timestamp(snum);
 		SAFE_FREE(queue);
 		return WERR_OK;
 	}
 
 	switch (level) {
 	case 1:
-		return enumjobs_level1(queue, snum, buffer, offered, needed, returned);
+		wret = enumjobs_level1(queue, snum, buffer, offered, needed, returned);
+		set_enumjobs_timestamp(snum);
+		return wret;
 	case 2:
-		return enumjobs_level2(queue, snum, buffer, offered, needed, returned);
+		wret = enumjobs_level2(queue, snum, buffer, offered, needed, returned);
+		set_enumjobs_timestamp(snum);
+		return wret;
 	default:
 		SAFE_FREE(queue);
 		*returned=0;