> Maybe the request is running in a different thread each time. Of course. Jetty has a thread pool and each requests gets an available thread from the pool semi-randomly. Note that qtp1248572294-23 and qtp1248572294-19 are also Jetty threads, so they are called within a request. So make sure you call ‘setTheUserId’ in every single request (and reset it to null at the end of that request).
Andrus On Aug 2, 2014, at 2:48 AM, D Tim Cummings <[email protected]> wrote: > Hi Andrus > > Thanks for your help. Here are logs with thread names as well. I logged in in > Thread 24 and created 5 new records. AuditListener is running in different > threads. I am running this in Eclipse 4.3.2 with the RunJettyRun plugin > running Jetty 8.1.2. Log statement is > > logger.info("Thread " + t.getId() + " " + t.getName() + " Looking for > TblPerson " + idUser); > //where t = Thread.currentThread() > > 2014-08-02 09:37:30,563 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 24 > qtp1248572294-24 setTheUserId 220 > 2014-08-02 09:38:14,064 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 24 > qtp1248572294-24 Looking for TblPerson 220 > 2014-08-02 09:38:14,064 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 24 > qtp1248572294-24 Looking for TblPerson 220 > 2014-08-02 09:38:14,064 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 24 > qtp1248572294-24 Looking for TblPerson 220 > 2014-08-02 09:38:14,065 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 24 > qtp1248572294-24 Looking for TblPerson 220 > 2014-08-02 09:38:31,045 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 23 > qtp1248572294-23 idUser == null > 2014-08-02 09:38:31,045 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 23 > qtp1248572294-23 idUser == null > 2014-08-02 09:38:31,045 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 23 > qtp1248572294-23 idUser == null > 2014-08-02 09:38:31,046 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 23 > qtp1248572294-23 idUser == null > 2014-08-02 09:38:57,932 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 19 > qtp1248572294-19 idUser == null > 2014-08-02 09:38:57,932 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 19 > qtp1248572294-19 idUser == null > 2014-08-02 09:38:57,932 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 19 > qtp1248572294-19 idUser == null > 2014-08-02 09:38:57,933 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 19 > qtp1248572294-19 idUser == null > 2014-08-02 09:39:16,048 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 23 > qtp1248572294-23 idUser == null > 2014-08-02 09:39:16,048 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 23 > qtp1248572294-23 idUser == null > 2014-08-02 09:39:16,048 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 23 > qtp1248572294-23 idUser == null > 2014-08-02 09:39:16,048 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 23 > qtp1248572294-23 idUser == null > 2014-08-02 09:39:41,670 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 24 > qtp1248572294-24 Looking for TblPerson 220 > 2014-08-02 09:39:41,670 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 24 > qtp1248572294-24 Looking for TblPerson 220 > 2014-08-02 09:39:41,670 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 24 > qtp1248572294-24 Looking for TblPerson 220 > 2014-08-02 09:39:41,670 INFO > [au.com.tramanco.chekway.cayenne.audit.AuditListener] Thread 24 > qtp1248572294-24 Looking for TblPerson 220 > > Maybe the request is running in a different thread each time. I will do some > more checking. > > Tim > > > On 1 Aug 2014, at 23:22, Andrus Adamchik <[email protected]> wrote: > >> Hi Tim, >> >> Yes you are going in the right direction with AuditableProcessor. >> >>> If I save the user in a ThreadLocal in the data channel filter object, I >>> get a different user each time (often blank) because the data channel >>> filter seem to run in its own thread which changes each time. >> >> This seems suspect. In a typical web app, all processing happens in request >> thread. Cayenne listeners are processed in the same thread as ObjectContext >> commit, which is normally your request thread. Could you possibly print >> thread names from within setTheUserId and doPrePersist methods ? Maybe that >> will give you a hint. Request threads in Tomcat and Jetty have easily >> identifiable names. >> >> Andrus >> >> >> On Jul 20, 2014, at 2:23 AM, D Tim Cummings <[email protected]> wrote: >> >>> Hi all >>> >>> I want to set up a simple audit trail which basically links who was the >>> person to create a record to that record. I am using Cayenne 3.2M1 and >>> Tapestry 5.3.7. I figure I need to set up a data channel filter to catch >>> changes to that record and then save a link to the user who made the >>> change. >>> >>> The problem is, if I save the user in the data channel filter object when >>> someone logs in, then all created records link to the last logged in user. >>> >>> If I save the user in a ThreadLocal in the data channel filter object, I >>> get a different user each time (often blank) because the data channel >>> filter seem to run in its own thread which changes each time. >>> >>> I have been watching the excellent and now freely available podcast by >>> Andrus Adamchik presented to WebObjects developers "Advanced Apache >>> Cayenne" where he talks about lifecycle events, (callbacks, listeners), >>> caching, data channel filters, clustering, in cayenne 3.2M1. >>> https://itunes.apple.com/podcast/webobjects-podcasts/id270165303?mt=2# >>> In Andrus's sample code he uses AuditableProcessor, but I couldn't think >>> how to use it to solve this problem. >>> >>> Here is a copy of my listener/data channel filter with the ThreadLocal code. >>> >>> Thanks >>> >>> Tim >>> >>> >>> public class AuditListener implements DataChannelFilter { >>> >>> private static final Logger logger = >>> LoggerFactory.getLogger(AuditListener.class); >>> >>> private ThreadLocal<Integer> tlUserId; >>> >>> @PrePersist(entityAnnotations=TagCreateCancel.class) >>> void doPrePersist(DataObject object) { >>> if ( object instanceof AuditableCreateCancel ) { >>> AuditableCreateCancel acc = (AuditableCreateCancel) object; >>> TblPerson user = getTheUser(object.getObjectContext()); >>> acc.setTblPersonCreate(user); >>> } >>> } >>> >>> private TblPerson getTheUser(ObjectContext oc) { >>> Thread t = Thread.currentThread(); >>> Integer idUser = tlUserId.get(); >>> if ( idUser == null ) { >>> logger.info("Thread " + t.getId() + " idUser == null "); >>> return null; >>> } >>> logger.info("Thread " + t.getId() + " Looking for TblPerson " + idUser); >>> TblPerson p = Cayenne.objectForPK(oc, TblPerson.class, idUser.intValue()); >>> return p; >>> } >>> >>> @Override >>> public void init(DataChannel channel) { >>> tlUserId = new ThreadLocal<Integer>(); >>> } >>> >>> @Override >>> public QueryResponse onQuery(ObjectContext originatingContext, Query query, >>> DataChannelFilterChain filterChain) { >>> return filterChain.onQuery(originatingContext, query); >>> } >>> >>> @Override >>> public GraphDiff onSync(ObjectContext originatingContext, GraphDiff >>> changes, int syncType, DataChannelFilterChain filterChain) { >>> try { >>> return filterChain.onSync(originatingContext, changes, syncType); >>> } finally { >>> // >>> } >>> } >>> >>> public void setTheUserId(int idUser) { >>> Thread t = Thread.currentThread(); >>> logger.info("Thread " + t.getId() + " setTheUserId " + idUser); >>> tlUserId.set(Integer.valueOf(idUser)); >>> } >>> >>> } >>> >> >
