11 Replies Latest reply: May 23, 2012 2:04 PM by 803774 RSS

    JMS queue notification delays

    803774
      We've noticed that when we import large calendars that there is a delay in some of the events propagating to attendee calendars. We assume that there is some sort of a delay or backlog in the JMS queue.

      1) how do you monitor the delay? I tried looking at NumMsgsIn and NumMsgsOut in mbean = com.sun.messaging.jms.server:desttype=t,name="DavNotificationTopic",subtype=Monitor,type=Destination. I expected to see NumMsgsIn greater than NumMsgsOut during the period of sync delay, but they were actually pretty equal the whole time.

      2) how do you tune the server to reduce or eliminate the delay?
        • 1. Re: JMS queue notification delays
          arnaudq
          Well, in theory, import does not trigger scheduling: the reasoning behind this is that end user sometime delete their calendar and reimport stuff several times. Now your description seems to indicate that you actually see those import trigger scheduling, except in a few cases.
          Do you import via WCAP or the davadmin command ?

          Then, the actual scheduling does not rely on JMS. Only notifications do. To see what is happening in terms of scheduling, you can have a look at the scheduling log file (scheduling.xx). Whenever an invitation (or reply) goes out, you should see an E entry. When that invitation reaches individual attendees, you should see a DL entry. See https://wikis.oracle.com/display/CommSuite7U1090210/Calendar+Server+7+Administration+Guide#CalendarServer7AdministrationGuide-AdministeringCalendarServer7Logging for the full list of codes.
          • 2. Re: JMS queue notification delays
            arnaudq
            I guess, you may be importing by doing individual event creation using HTTP PUT. That would explain why scheduling is actually happening. What kind of delay are we talking about ? The scheduling log file should definitely help you measure that.
            • 3. Re: JMS queue notification delays
              803774
              Import is being done via CalDAV PUT with proxyauth.
              • 4. Re: JMS queue notification delays
                803774
                On Friday we were seeing severe delays, so bad that we assumed that invitations were completely failing. I was actively testing over the course of several hours, and saw no indication of invitations being sent successfully. I opened a case under the assumption that the application of patch 142785-06 broke something. On Monday we discovered that the invitations had since arrived, and that there were no active delays.

                We're still trying to determine what triggered the severe scheduling delays. At least we would like to find a way to monitor this behavior. We only know that we can trigger slight delays when importing (via HTTP PUT) a large calendar.
                • 5. Re: JMS queue notification delays
                  803774
                  Oh, and to answer your other question. We were seeing "E" logs (immediately) in the scheduling log during the period in which no invitations were propagating.

                  [13/Apr/2012:04:22:02 -0500] E "prodimport.mailstone.testuser620111215@wisctest.wisc.edu/calendar-outbox/REQUEST-1334352122621-5-.ics" 35029dcd-30a2-4fb5-80e0-89589d09346a REQUEST mailto:mailstone.testuser6@wisctest.wisc.edu mailto:mailstone.testuser3@wisctest.wisc.edu "1.2;Delivered"
                  • 6. Re: JMS queue notification delays
                    803774
                    Maybe my assumption that the backlog occurring in the JMS queue is incorrect. Could the backlog be occurring in the "calendar-outboxes" of the users? Is there a way to monitor that?
                    • 7. Re: JMS queue notification delays
                      arnaudq
                      Yes and no. Yes, scheduling messages are deposited into individual users outboxes when the PUT on the calendar collection happens. But those scheduling messages are not removed from there immediately once processed (although they are purged after some time). A global internal queue is processing those messages asynchronously, adding the corresponding event into attendees calendars as needed.
                      If you have a large calendar with a lot of events, themselves with a lot of attendees, the queue can grow quite large and take some time to process all those scheduling messages. There is currently no way to monitor this internal queue (well, unless you are ready to play with some SQL commands). On the other hand, by looking at the scheduling log, you can track the gap between messages that have been enqueued (second column is "E") and messages that have been delivered ("DL" or "DE", "DM" or "R"). It should come down to zero when all are processed. By looking at the 4th column, you can track the processing of a particular event (it corresponds to the event UID).
                      • 8. Re: JMS queue notification delays
                        803774
                        Thanks. It is useful in knowing that the scheduling log entries will be a reliable method of monitoring for scheduling backlogs.

                        Of course, if anyone knows of the SQL required to get at the internal queue information, it would be also be very helpful.
                        • 9. Re: JMS queue notification delays
                          803774
                          Is it correct to assume that there will never be a "DL" log entry when the "E" entry says "1.2;Delivered"?
                          • 10. Re: JMS queue notification delays
                            arnaudq
                            It looks like you figured that out by yourself but just for the record:

                            E, J, QE, QM, R entries are logged at INFO level.
                            All other entries are logged at FINE level.

                            In other words, by setting the log.dav.scheduling.loglevel configuration parameter to FINE, you should see all entries.
                            • 11. Re: JMS queue notification delays
                              803774
                              Thanks for the clarification.