Sync Service Working But Web Service Does NOT Return Results to Google Scheduler

15 views

Skip to first unread message

Richard Champlin

unread,

Oct 27, 2010, 3:03:58 PM10/27/10

to google-calendar-connectors

Sync Service appears to be working.

Web Service fails to return the exchange user Free/Busy info to the
browser; however, it appears to work properly for everything up to
that point. Here is the log for a gcal-only (mail-enabled contact)
user trying to access exchange-only user's Free/Busy info through the
google scheduler (the browser request is generated from internal to
the network/not over the internet):

2010-10-27 13:47:53,585 [3980] INFO
Google.GCalExchangeSync.Library.GCalFreeBusyRequest - Request received
from GCal. [body=[1,0,[geoff...@uwmidsouth.org],
20101021/20101108,20101027T134808,America/Chicago]]
2010-10-27 13:47:53,600 [3980] INFO
Google.GCalExchangeSync.Library.ConfigCache - Added Domain Map.
gapp.uwmidsouth.org <-> uwmidsouth.org
2010-10-27 13:47:53,678 [3980] INFO
Google.GCalExchangeSync.Library.ActiveDirectoryService - Issuing LDAP
query '(&(mail=geoff...@uwmidsouth.org)(|(objectcategory=user)
(objectcategory=contact)))'
2010-10-27 13:47:53,803 [3980] INFO
Google.GCalExchangeSync.Library.ActiveDirectoryService - Found 0 users
in Active Directory.
2010-10-27 13:47:53,803 [3980] WARN
Google.GCalExchangeSync.Library.ExchangeFreeBusyProvider - Could not
find user 'geoff...@uwmidsouth.org'.
2010-10-27 13:47:53,819 [3980] INFO
Google.GCalExchangeSync.Library.GCalFreeBusyResponse - GCal Free/Busy
response successfully generated.
2010-10-27 13:47:53,819 [3980] DEBUG
Google.GCalExchangeSync.Library.GCalFreeBusyResponse - Response =
['1','0',['_ME_AddData','20101021/20101108','20101027T134808',[]]]
2010-10-27 13:47:53,819 [3980] DEBUG
GCalExchangeLookup.ExchangeQuerierBase - Use SSL True
2010-10-27 13:47:53,819 [3980] DEBUG
GCalExchangeLookup.ExchangeQuerierBase - Request URL
https://gcal.uwmidsouth.org/gcalexchangelookup/exchangequerier.aspx
2010-10-27 13:47:53,819 [3980] DEBUG
GCalExchangeLookup.ExchangeQuerierBase - Referrer URL
2010-10-27 13:48:08,803 [4436] INFO
Google.GCalExchangeSync.Library.GCalFreeBusyRequest - Request received
from GCal. [body=[1,1,[firstname...@uwmidsouth.org],
20101021/20101108,20101027T134753,America/Chicago]]
2010-10-27 13:48:08,803 [4436] INFO
Google.GCalExchangeSync.Library.ActiveDirectoryService - Issuing LDAP
query '(&(mail=firstname...@uwmidsouth.org)(|
(objectcategory=user)(objectcategory=contact)))'
2010-10-27 13:48:08,881 [4436] INFO
Google.GCalExchangeSync.Library.ActiveDirectoryService - Found 1 users
in Active Directory.
2010-10-27 13:48:08,881 [4436] INFO
Google.GCalExchangeSync.Library.ExchangeService - Found and added
'firstname...@uwmidsouth.org' as an ExchangeUser.
2010-10-27 13:48:08,881 [4436] DEBUG
Google.GCalExchangeSync.Library.ExchangeService - LDAP object debug
info: [ProxyAddresses=SMTP:firstname...@uwmidsouth.org,
sAMAccountName=lastnameJ, mailnickname=lastnameJ,
mail=firstname...@uwmidsouth.org, CN=firstname lastname,
legacyExchangeDN=/o=UWMS/ou=uwmail/cn=Recipients/cn=lastnameJ,
DN=CN=firstname
lastname,OU=Docs2_redirect,OU=uwmsintra_users,DC=uwmsintra,DC=org,
objectClass=[ top, person, organizationalPerson, user ]]
2010-10-27 13:48:08,897 [4436] DEBUG
Google.GCalExchangeSync.Library.WebDav.XmlRequestImpl - Issuing WebDAV
Request: GET to
https://owa.uwmidsouth.org/public/?cmd=freebusy&start=2010-10-21T05:00:00Z&end=2010-11-08T06:00:00Z&interval=15&u=firstname...@uwmidsouth.org
- Group Exchange
2010-10-27 13:48:09,022 [4436] DEBUG
Google.GCalExchangeSync.Library.FreeBusyConverter - Parsing the raster
0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000003333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333330000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000002222000000000000000000000000000000003333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333330000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
2010-10-27 13:48:09,022 [4436] DEBUG
Google.GCalExchangeSync.Library.FreeBusyConverter - Parsed the raster
into 1 busy and 0 tentative ranges
2010-10-27 13:48:09,037 [4436] INFO
Google.GCalExchangeSync.Library.Util.BlockTimer - [Timer] -
LookupFreeBusyTimes - Total Execution Time: 141 ms.
2010-10-27 13:48:09,037 [4436] INFO
Google.GCalExchangeSync.Library.ExchangeService - Busy: 1, Tentative:
0, OOO: 2, All: 3
2010-10-27 13:48:09,053 [4436] INFO
Google.GCalExchangeSync.Library.ExchangeService - Merge Result 3 -> 3
2010-10-27 13:48:09,053 [4436] INFO
Google.GCalExchangeSync.Library.ExchangeService - Merged with 0
Appointments
2010-10-27 13:48:09,053 [4436] INFO
Google.GCalExchangeSync.Library.Util.BlockTimer - [Timer] -
MergeFreeBusyWithAppointments - Total Execution Time: 16 ms.
2010-10-27 13:48:09,053 [4436] DEBUG
Google.GCalExchangeSync.Library.ConfigCache - Mapping:
firstname...@uwmidsouth.org
2010-10-27 13:48:09,053 [4436] INFO
Google.GCalExchangeSync.Library.GCalFreeBusyResponse - GCal Free/Busy
response successfully generated.
2010-10-27 13:48:09,053 [4436] DEBUG
Google.GCalExchangeSync.Library.GCalFreeBusyResponse - Response =
['1','1',['_ME_AddData','20101021/20101108','20101027T134753',
['firstname lastname','firstname\056lastname\100gapp\056uwmidsouth
\056org','20',[['','20101025T000000','20101027T000000','','firstname
lastname',1],['','20101028T150000','20101028T160000','','firstname
lastname',1],['','20101029T000000','20101030T000000','','firstname
lastname',1]]]]]
2010-10-27 13:48:09,053 [4436] DEBUG
GCalExchangeLookup.ExchangeQuerierBase - Use SSL True
2010-10-27 13:48:09,053 [4436] DEBUG
GCalExchangeLookup.ExchangeQuerierBase - Request URL
https://gcal.uwmidsouth.org/gcalexchangelookup/exchangequerier.aspx
2010-10-27 13:48:09,053 [4436] DEBUG
GCalExchangeLookup.ExchangeQuerierBase - Referrer URL

END LOG

I am not doing appointment lookup; only Free/Busy. I have verified
that http-keep-alives are enabled. I doubled the timeout from 120 to
240. I am using version 1.3.1 of the webservice.

Thanks!

Richard Champlin

unread,

Oct 29, 2010, 4:22:54 PM10/29/10

to google-calendar-connectors

Still no help?

I have to believe that my issue is the roundtrip communication with
google servers through our back to back ISA firewalls. I believe that
would be an issue whether or not the browser itself were inside or
outside our network, right?

The only part that fails as far as I can tell is the return of the
merged free/busy response from the websvc to google's servers prior to
being delivered from google's servers to my browser. Is that the right
breakdown of traffic?

I am not sure I understand the flow correctly...WHAT would prevent
ONLY the websvc from successfully using HTTP POST "to send the
combined free/busy back to Google Calendar's Scheduler"? (And does
that traffic actually have to flow out my network through my firewalls
directly from the websvc to google, and then back in to the browser?

Assuming it does flow as I have described, what can I do in order to
properly authenticate (or exempt successfully) the websvc (and
whatever account it's using).

If I misunderstand the flow, what other options are there from
tracking down the failure?

Thanks! (Should I post this as an issue?)

On Oct 27, 2:03 pm, Richard Champlin <richard.champ...@uwmidsouth.org>
wrote:

> Sync Service appears to be working.
>
> Web Service fails to return the exchange user Free/Busy info to the
> browser; however, it appears to work properly for everything up to
> that point. Here is the log for a gcal-only (mail-enabled contact)
> user trying to access exchange-only user's Free/Busy info through the
> google scheduler (the browser request is generated from internal to
> the network/not over the internet):
>
> 2010-10-27 13:47:53,585 [3980] INFO
> Google.GCalExchangeSync.Library.GCalFreeBusyRequest - Request received

> from GCal. [body=[1,0,[geoff.g...@uwmidsouth.org],

> 20101021/20101108,20101027T134808,America/Chicago]]
> 2010-10-27 13:47:53,600 [3980] INFO
> Google.GCalExchangeSync.Library.ConfigCache - Added Domain Map.
> gapp.uwmidsouth.org <-> uwmidsouth.org
> 2010-10-27 13:47:53,678 [3980] INFO
> Google.GCalExchangeSync.Library.ActiveDirectoryService - Issuing LDAP

> query '(&(mail=geoff.g...@uwmidsouth.org)(|(objectcategory=user)

> (objectcategory=contact)))'
> 2010-10-27 13:47:53,803 [3980] INFO
> Google.GCalExchangeSync.Library.ActiveDirectoryService - Found 0 users
> in Active Directory.
> 2010-10-27 13:47:53,803 [3980] WARN
> Google.GCalExchangeSync.Library.ExchangeFreeBusyProvider - Could not

> find user 'geoff.g...@uwmidsouth.org'.

> 2010-10-27 13:47:53,819 [3980] INFO
> Google.GCalExchangeSync.Library.GCalFreeBusyResponse - GCal Free/Busy
> response successfully generated.
> 2010-10-27 13:47:53,819 [3980] DEBUG
> Google.GCalExchangeSync.Library.GCalFreeBusyResponse - Response =
> ['1','0',['_ME_AddData','20101021/20101108','20101027T134808',[]]]
> 2010-10-27 13:47:53,819 [3980] DEBUG
> GCalExchangeLookup.ExchangeQuerierBase - Use SSL True
> 2010-10-27 13:47:53,819 [3980] DEBUG

> GCalExchangeLookup.ExchangeQuerierBase - Request URLhttps://gcal.uwmidsouth.org/gcalexchangelookup/exchangequerier.aspx

> 2010-10-27 13:47:53,819 [3980] DEBUG
> GCalExchangeLookup.ExchangeQuerierBase - Referrer URL
> 2010-10-27 13:48:08,803 [4436] INFO
> Google.GCalExchangeSync.Library.GCalFreeBusyRequest - Request received

> from GCal. [body=[1,1,[firstname.lastn...@uwmidsouth.org],

> 20101021/20101108,20101027T134753,America/Chicago]]
> 2010-10-27 13:48:08,803 [4436] INFO
> Google.GCalExchangeSync.Library.ActiveDirectoryService - Issuing LDAP

> query '(&(mail=firstname.lastn...@uwmidsouth.org)(|

> (objectcategory=user)(objectcategory=contact)))'
> 2010-10-27 13:48:08,881 [4436] INFO
> Google.GCalExchangeSync.Library.ActiveDirectoryService - Found 1 users
> in Active Directory.
> 2010-10-27 13:48:08,881 [4436] INFO
> Google.GCalExchangeSync.Library.ExchangeService - Found and added

> 'firstname.lastn...@uwmidsouth.org' as an ExchangeUser.

> 2010-10-27 13:48:08,881 [4436] DEBUG
> Google.GCalExchangeSync.Library.ExchangeService - LDAP object debug

> info: [ProxyAddresses=SMTP:firstname.lastn...@uwmidsouth.org,
> sAMAccountName=lastnameJ, mailnickname=lastnameJ,
> mail=firstname.lastn...@uwmidsouth.org, CN=firstname lastname,

> legacyExchangeDN=/o=UWMS/ou=uwmail/cn=Recipients/cn=lastnameJ,
> DN=CN=firstname
> lastname,OU=Docs2_redirect,OU=uwmsintra_users,DC=uwmsintra,DC=org,
> objectClass=[ top, person, organizationalPerson, user ]]
> 2010-10-27 13:48:08,897 [4436] DEBUG
> Google.GCalExchangeSync.Library.WebDav.XmlRequestImpl - Issuing WebDAV
> Request: GET to

> https://owa.uwmidsouth.org/public/?cmd=freebusy&start=2010-10-21T05:00:00Z& end=2010-11-08T06:00:00Z&interval=15&u=firstname.lastn...@uwmidsouth.org

> - Group Exchange
> 2010-10-27 13:48:09,022 [4436] DEBUG
> Google.GCalExchangeSync.Library.FreeBusyConverter - Parsing the raster
> 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000333333333333333333333333333333333333333333333333333333333333333333 333333333333333333333333333333333333333333333333333333333333333333333333333 333333333333333333333333333333333333333333333333333000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000222200000000000000 000000000000000000333333333333333333333333333333333333333333333333333333333 333333333333333333333333333333333333333000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 0000000
> 2010-10-27 13:48:09,022 [4436] DEBUG
> Google.GCalExchangeSync.Library.FreeBusyConverter - Parsed the raster
> into 1 busy and 0 tentative ranges
> 2010-10-27 13:48:09,037 [4436] INFO
> Google.GCalExchangeSync.Library.Util.BlockTimer - [Timer] -
> LookupFreeBusyTimes - Total Execution Time: 141 ms.
> 2010-10-27 13:48:09,037 [4436] INFO
> Google.GCalExchangeSync.Library.ExchangeService - Busy: 1, Tentative:
> 0, OOO: 2, All: 3
> 2010-10-27 13:48:09,053 [4436] INFO
> Google.GCalExchangeSync.Library.ExchangeService - Merge Result 3 -> 3
> 2010-10-27 13:48:09,053 [4436] INFO
> Google.GCalExchangeSync.Library.ExchangeService - Merged with 0
> Appointments
> 2010-10-27 13:48:09,053 [4436] INFO
> Google.GCalExchangeSync.Library.Util.BlockTimer - [Timer] -
> MergeFreeBusyWithAppointments - Total Execution Time: 16 ms.
> 2010-10-27 13:48:09,053 [4436] DEBUG
> Google.GCalExchangeSync.Library.ConfigCache - Mapping:

> firstname.lastn...@uwmidsouth.org

> 2010-10-27 13:48:09,053 [4436] INFO
> Google.GCalExchangeSync.Library.GCalFreeBusyResponse - GCal Free/Busy
> response successfully generated.
> 2010-10-27 13:48:09,053 [4436] DEBUG
> Google.GCalExchangeSync.Library.GCalFreeBusyResponse - Response =
> ['1','1',['_ME_AddData','20101021/20101108','20101027T134753',
> ['firstname lastname','firstname\056lastname\100gapp\056uwmidsouth
> \056org','20',[['','20101025T000000','20101027T000000','','firstname
> lastname',1],['','20101028T150000','20101028T160000','','firstname
> lastname',1],['','20101029T000000','20101030T000000','','firstname
> lastname',1]]]]]
> 2010-10-27 13:48:09,053 [4436] DEBUG
> GCalExchangeLookup.ExchangeQuerierBase - Use SSL True
> 2010-10-27 13:48:09,053 [4436] DEBUG

> GCalExchangeLookup.ExchangeQuerierBase - Request URLhttps://gcal.uwmidsouth.org/gcalexchangelookup/exchangequerier.aspx

Darrell Kuhn ☯

unread,

Oct 29, 2010, 6:25:06 PM10/29/10

to google-calend...@googlegroups.com

See comments in-line.

On Fri, Oct 29, 2010 at 1:22 PM, Richard Champlin <richard....@uwmidsouth.org> wrote:

Still no help?

I have to believe that my issue is the roundtrip communication with
google servers through our back to back ISA firewalls. I believe that
would be an issue whether or not the browser itself were inside or
outside our network, right?

The only part that fails as far as I can tell is the return of the
merged free/busy response from the websvc to google's servers prior to
being delivered from google's servers to my browser. Is that the right
breakdown of traffic?

I am not sure I understand the flow correctly...WHAT would prevent
ONLY the websvc from successfully using HTTP POST "to send the
combined free/busy back to Google Calendar's Scheduler"? (And does
that traffic actually have to flow out my network through my firewalls
directly from the websvc to google, and then back in to the browser?

When getting free/busy from within Google Calendar the requests are initiated by the client browser. It will posted the request to the web service to get the free/busy data from exchange. Then it takes that data and posts the data to Google Calendar to then render on the Google Calendar web page. You can use firebug in firefox or Chrome to watch the process and see where the responses are failing.

Sounds like what might be failing is the POST back to Google Calendar, if this is the case you will see that in the firebug results. Please check those results and let us know what you are seeing

--
You received this message because you are subscribed to the Google Groups "google-calendar-connectors" group.
To post to this group, send email to google-calend...@googlegroups.com.
To unsubscribe from this group, send email to google-calendar-con...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/google-calendar-connectors?hl=en.

--
You received this message because you are subscribed to the Google Groups "opensource-google-calendar-connectors" group.
To post to this group, send email to opensource-google-...@google.com.
To unsubscribe from this group, send email to opensource-google-calend...@google.com.
For more options, visit this group at http://groups.google.com/a/google.com/group/opensource-google-calendar-connectors/?hl=en.

Richard Champlin

unread,

Nov 2, 2010, 4:28:24 PM11/2/10

to google-calendar-connectors

Here is Firebug output.

Note the result in both cases is the same (indicating success),
however the exchange user's data is not actually being returned.

Below the firebug data, I have included the webservice log data
showing that *actual* response (that should have been returned for the
exchange user) was successfully generated...

GCAL-Only USER Firebug Output:

POST meeting 200 OK 293ms

while(1);[['_ME_AddData','20101027/20101114','20101102T151200',
['Z2VvZmYuZ2NhbEB1d21pZHNvdXRoLm9yZw','geoff...@uwmidsouth.org','geoff...@uwmidsouth.org',
80,[['just to check that sync is
working!','20101028T090000','20101028T170000','','Geoff Gcal',5],
['Fictional Meeting','20101027T093000','20101027T100000','Fictional
Place','dave.s...@uwmidsouth.org',0],['test for
research','20101029T130000','20101029T140000','','Geoff Gcal',1],
['Review of Geoff\47s
orientation','20101027T130000','20101027T133000','','Richard Champlin',
1],['geoff orientation','20101027T120000','20101027T130000','','Geoff
Gcal',1],['Celebration for getting Sync
to','20101027T140000','20101027T150000','','Geoff Gcal',5],['12:10 pm
from cashion (remotely)','20101027T160000','20101027T170000','','Geoff
Gcal',5]]]]]

EXCHANGE USER Firebug Output:

POST meeting 200 OK 281ms

RESPONSE:
while(1);[['_ME_AddData','20101027/20101114','00001231T000000',
['ZGF2ZS5za29ydXBhQHV3bWlkc291dGgub3Jn','dave.s...@uwmidsouth.org','dave.s...@uwmidsouth.org',
0,[]]]]

Here is the web service log data, showing that the ldap and exchange
queries both work properly:

2010-11-02 15:12:00,146 [12108] INFO
Google.GCalExchangeSync.Library.GCalFreeBusyRequest - Request received
from GCal. [body=[1,1,[geoff...@uwmidsouth.org],
20101027/20101114,20101102T151148,America/Chicago]]
2010-11-02 15:12:00,146 [12108] INFO
Google.GCalExchangeSync.Library.ActiveDirectoryService - Issuing LDAP
query '(&(mail=geoff...@uwmidsouth.org)(|(objectcategory=user)
(objectcategory=contact)))'
2010-11-02 15:12:00,177 [12108] INFO

Google.GCalExchangeSync.Library.ActiveDirectoryService - Found 0 users
in Active Directory.

2010-11-02 15:12:00,177 [12108] WARN
Google.GCalExchangeSync.Library.ExchangeFreeBusyProvider - Could not
find user 'geoff...@uwmidsouth.org'.
2010-11-02 15:12:00,177 [12108] INFO

Google.GCalExchangeSync.Library.GCalFreeBusyResponse - GCal Free/Busy
response successfully generated.

2010-11-02 15:12:00,177 [12108] DEBUG
Google.GCalExchangeSync.Library.GCalFreeBusyResponse - Response =
['1','1',['_ME_AddData','20101027/20101114','20101102T151148',[]]]
2010-11-02 15:12:00,177 [12108] DEBUG

GCalExchangeLookup.ExchangeQuerierBase - Use SSL True

2010-11-02 15:12:00,177 [12108] DEBUG

GCalExchangeLookup.ExchangeQuerierBase - Request URL
https://gcal.uwmidsouth.org/gcalexchangelookup/exchangequerier.aspx

2010-11-02 15:12:00,177 [12108] DEBUG
GCalExchangeLookup.ExchangeQuerierBase - Referrer URL
2010-11-02 15:12:12,536 [12108] INFO
Google.GCalExchangeSync.Library.GCalFreeBusyRequest - Request received
from GCal. [body=[1,2,[dave.s...@uwmidsouth.org],
20101027/20101114,20101102T151200,America/Chicago]]
2010-11-02 15:12:12,536 [12108] INFO
Google.GCalExchangeSync.Library.ActiveDirectoryService - Issuing LDAP
query '(&(mail=dave.s...@uwmidsouth.org)(|(objectcategory=user)
(objectcategory=contact)))'
2010-11-02 15:12:12,568 [12108] INFO

Google.GCalExchangeSync.Library.ActiveDirectoryService - Found 1 users
in Active Directory.

2010-11-02 15:12:12,568 [12108] INFO

Google.GCalExchangeSync.Library.ExchangeService - Found and added

'dave.s...@uwmidsouth.org' as an ExchangeUser.
2010-11-02 15:12:12,568 [12108] DEBUG

Google.GCalExchangeSync.Library.ExchangeService - LDAP object debug

info: [ProxyAddresses=SMTP:dave.s...@uwmidsouth.org,
sAMAccountName=SkorupaD, mailnickname=SkorupaD,
mail=dave.s...@uwmidsouth.org, CN=Dave Skorupa, legacyExchangeDN=/
o=UWMS/ou=uwmail/cn=Recipients/cn=SkorupaD, DN=CN=Dave
Skorupa,OU=Docs2_redirect,OU=uwmsintra_users,DC=uwmsintra,DC=org,

objectClass=[ top, person, organizationalPerson, user ]]

2010-11-02 15:12:12,568 [12108] DEBUG

Google.GCalExchangeSync.Library.WebDav.XmlRequestImpl - Issuing WebDAV
Request: GET to

https://owa.uwmidsouth.org/public/?cmd=freebusy&start=2010-10-27T05:00:00Z&end=2010-11-14T06:00:00Z&interval=15&u=dave.s...@uwmidsouth.org
- Group Exchange
2010-11-02 15:12:12,583 [12108] DEBUG

Google.GCalExchangeSync.Library.FreeBusyConverter - Parsing the raster

4444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444444000000000000000000000000000000000000000000000000000000000000000000000000000000000022220000000000000000000000000000000000000000000000000000000000000000000000000000000000002222220000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000003333333000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000002222000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000002222220000000000000000000000000000000000000333333300000000000000333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333
2010-11-02 15:12:12,583 [12108] DEBUG

Google.GCalExchangeSync.Library.FreeBusyConverter - Parsed the raster

into 4 busy and 0 tentative ranges
2010-11-02 15:12:12,583 [12108] INFO
Google.GCalExchangeSync.Library.Util.BlockTimer - [Timer] -
LookupFreeBusyTimes - Total Execution Time: 16 ms.
2010-11-02 15:12:12,583 [12108] INFO
Google.GCalExchangeSync.Library.ExchangeService - Busy: 4, Tentative:
0, OOO: 3, All: 7
2010-11-02 15:12:12,583 [12108] INFO
Google.GCalExchangeSync.Library.ExchangeService - Merge Result 7 -> 7
2010-11-02 15:12:12,583 [12108] INFO

Google.GCalExchangeSync.Library.ExchangeService - Merged with 0
Appointments

2010-11-02 15:12:12,583 [12108] INFO
Google.GCalExchangeSync.Library.Util.BlockTimer - [Timer] -
MergeFreeBusyWithAppointments - Total Execution Time: 0 ms.
2010-11-02 15:12:12,583 [12108] DEBUG
Google.GCalExchangeSync.Library.ConfigCache - Mapping:
dave.s...@uwmidsouth.org
2010-11-02 15:12:12,583 [12108] INFO

Google.GCalExchangeSync.Library.GCalFreeBusyResponse - GCal Free/Busy
response successfully generated.

2010-11-02 15:12:12,583 [12108] DEBUG
Google.GCalExchangeSync.Library.GCalFreeBusyResponse - Response =
['1','2',['_ME_AddData','20101027/20101114','20101102T151200',['Dave
Skorupa','dave\056skorupa\100gapp\056uwmidsouth\056org','20',
[['','20101101T153000','20101101T163000','','Dave Skorupa',1],
['','20101102T133000','20101102T150000','','Dave Skorupa',1],
['','20101103T184500','20101103T203000','','Dave Skorupa',1],
['','20101108T153000','20101108T163000','','Dave Skorupa',1],
['','20101110T080000','20101110T093000','','Dave Skorupa',1],
['','20101110T184500','20101110T203000','','Dave Skorupa',1],
['','20101111T000000','20101114T000000','','Dave Skorupa',1]]]]]
2010-11-02 15:12:12,583 [12108] DEBUG

GCalExchangeLookup.ExchangeQuerierBase - Use SSL True

2010-11-02 15:12:12,583 [12108] DEBUG

GCalExchangeLookup.ExchangeQuerierBase - Request URL
https://gcal.uwmidsouth.org/gcalexchangelookup/exchangequerier.aspx

2010-11-02 15:12:12,583 [12108] DEBUG
GCalExchangeLookup.ExchangeQuerierBase - Referrer URL

I am really kinda stuck here. Any help?

> > > info: [ProxyAddresses=SMTP:firstname.lastn...@uwmidsouth.org<SMTP%3Afirstname.lastn...@uwmidsouth.org>
> > ,

> > > sAMAccountName=lastnameJ, mailnickname=lastnameJ,
> > > mail=firstname.lastn...@uwmidsouth.org, CN=firstname lastname,
> > > legacyExchangeDN=/o=UWMS/ou=uwmail/cn=Recipients/cn=lastnameJ,
> > > DN=CN=firstname
> > > lastname,OU=Docs2_redirect,OU=uwmsintra_users,DC=uwmsintra,DC=org,
> > > objectClass=[ top, person, organizationalPerson, user ]]
> > > 2010-10-27 13:48:08,897 [4436] DEBUG
> > > Google.GCalExchangeSync.Library.WebDav.XmlRequestImpl - Issuing WebDAV
> > > Request: GET to
>

> >https://owa.uwmidsouth.org/public/?cmd=freebusy&start=2010-10-21T05:0...
> > firstname.lastn...@uwmidsouth.org

> ...
>
> read more »

Jaideep Garg

unread,

Nov 3, 2010, 1:40:21 AM11/3/10

to google-calend...@googlegroups.com

Hi,

What version of web service are you using ? If multidomain or multilogin is enabled, the older version of web service would post back to wrong url. Please use the latest web service version 1.3.1

Thanks,
Jaideep

To post to this group, send email to google-calend...@googlegroups.com.
To unsubscribe from this group, send email to google-calendar-con...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/google-calendar-connectors?hl=en.

--

Richard Champlin

unread,

Nov 3, 2010, 11:49:09 AM11/3/10

to google-calendar-connectors

I am using the 1.3.1 version downloaded from here. (Only version we
have tried.)

On Nov 2, 11:40 pm, Jaideep Garg <jaideepg...@google.com> wrote:
> Hi,
>
> What version of web service are you using ? If multidomain or multilogin is
> enabled, the older version of web service would post back to wrong url.
> Please use the latest web service version 1.3.1
>

> *Thanks,
> Jaideep *

>
> On Wed, Nov 3, 2010 at 1:58 AM, Richard Champlin <
>
>
>
>
>
>
>
> richard.champ...@uwmidsouth.org> wrote:
> > Here is Firebug output.
>
> > Note the result in both cases is the same (indicating success),
> > however the exchange user's data is not actually being returned.
>
> > Below the firebug data, I have included the webservice log data
> > showing that *actual* response (that should have been returned for the
> > exchange user) was successfully generated...
>
> > GCAL-Only USER Firebug Output:
>
> > POST meeting 200 OK 293ms
>
> > while(1);[['_ME_AddData','20101027/20101114','20101102T151200',

> > ['Z2VvZmYuZ2NhbEB1d21pZHNvdXRoLm9yZw','geoff.g...@uwmidsouth.org','
> > geoff.g...@uwmidsouth.org',

> > 80,[['just to check that sync is
> > working!','20101028T090000','20101028T170000','','Geoff Gcal',5],
> > ['Fictional Meeting','20101027T093000','20101027T100000','Fictional

> > Place','dave.skor...@uwmidsouth.org',0],['test for

> > research','20101029T130000','20101029T140000','','Geoff Gcal',1],
> > ['Review of Geoff\47s
> > orientation','20101027T130000','20101027T133000','','Richard Champlin',
> > 1],['geoff orientation','20101027T120000','20101027T130000','','Geoff
> > Gcal',1],['Celebration for getting Sync
> > to','20101027T140000','20101027T150000','','Geoff Gcal',5],['12:10 pm
> > from cashion (remotely)','20101027T160000','20101027T170000','','Geoff
> > Gcal',5]]]]]
>
> > EXCHANGE USER Firebug Output:
>
> > POST meeting 200 OK 281ms
>
> > RESPONSE:
> > while(1);[['_ME_AddData','20101027/20101114','00001231T000000',

> > ['ZGF2ZS5za29ydXBhQHV3bWlkc291dGgub3Jn','dave.skor...@uwmidsouth.org','
> > dave.skor...@uwmidsouth.org',

> > 0,[]]]]
>
> > Here is the web service log data, showing that the ldap and exchange
> > queries both work properly:
>
> > 2010-11-02 15:12:00,146 [12108] INFO
> > Google.GCalExchangeSync.Library.GCalFreeBusyRequest - Request received

> > from GCal. [body=[1,1,[geoff.g...@uwmidsouth.org],

> > 20101027/20101114,20101102T151148,America/Chicago]]
> > 2010-11-02 15:12:00,146 [12108] INFO
> > Google.GCalExchangeSync.Library.ActiveDirectoryService - Issuing LDAP

> > query '(&(mail=geoff.g...@uwmidsouth.org)(|(objectcategory=user)

> > (objectcategory=contact)))'
> > 2010-11-02 15:12:00,177 [12108] INFO
> > Google.GCalExchangeSync.Library.ActiveDirectoryService - Found 0 users
> > in Active Directory.
> > 2010-11-02 15:12:00,177 [12108] WARN
> > Google.GCalExchangeSync.Library.ExchangeFreeBusyProvider - Could not

> > find user 'geoff.g...@uwmidsouth.org'.

> > 2010-11-02 15:12:00,177 [12108] INFO
> > Google.GCalExchangeSync.Library.GCalFreeBusyResponse - GCal Free/Busy
> > response successfully generated.
> > 2010-11-02 15:12:00,177 [12108] DEBUG
> > Google.GCalExchangeSync.Library.GCalFreeBusyResponse - Response =
> > ['1','1',['_ME_AddData','20101027/20101114','20101102T151148',[]]]
> > 2010-11-02 15:12:00,177 [12108] DEBUG
> > GCalExchangeLookup.ExchangeQuerierBase - Use SSL True
> > 2010-11-02 15:12:00,177 [12108] DEBUG
> > GCalExchangeLookup.ExchangeQuerierBase - Request URL
> >https://gcal.uwmidsouth.org/gcalexchangelookup/exchangequerier.aspx
> > 2010-11-02 15:12:00,177 [12108] DEBUG
> > GCalExchangeLookup.ExchangeQuerierBase - Referrer URL
> > 2010-11-02 15:12:12,536 [12108] INFO
> > Google.GCalExchangeSync.Library.GCalFreeBusyRequest - Request received

> > from GCal. [body=[1,2,[dave.skor...@uwmidsouth.org],

> > 20101027/20101114,20101102T151200,America/Chicago]]
> > 2010-11-02 15:12:12,536 [12108] INFO
> > Google.GCalExchangeSync.Library.ActiveDirectoryService - Issuing LDAP

> > query '(&(mail=dave.skor...@uwmidsouth.org)(|(objectcategory=user)

> > (objectcategory=contact)))'
> > 2010-11-02 15:12:12,568 [12108] INFO
> > Google.GCalExchangeSync.Library.ActiveDirectoryService - Found 1 users
> > in Active Directory.
> > 2010-11-02 15:12:12,568 [12108] INFO
> > Google.GCalExchangeSync.Library.ExchangeService - Found and added

> > 'dave.skor...@uwmidsouth.org' as an ExchangeUser.

> > 2010-11-02 15:12:12,568 [12108] DEBUG
> > Google.GCalExchangeSync.Library.ExchangeService - LDAP object debug

> > info: [ProxyAddresses=SMTP:dave.skor...@uwmidsouth.org<SMTP%3Adave.skor...@uwmidsouth.org>
> > ,
> > sAMAccountName=SkorupaD, mailnickname=SkorupaD,
> > mail=dave.skor...@uwmidsouth.org, CN=Dave Skorupa, legacyExchangeDN=/

> > o=UWMS/ou=uwmail/cn=Recipients/cn=SkorupaD, DN=CN=Dave
> > Skorupa,OU=Docs2_redirect,OU=uwmsintra_users,DC=uwmsintra,DC=org,
> > objectClass=[ top, person, organizationalPerson, user ]]
> > 2010-11-02 15:12:12,568 [12108] DEBUG
> > Google.GCalExchangeSync.Library.WebDav.XmlRequestImpl - Issuing WebDAV
> > Request: GET to
>

> > https://owa.uwmidsouth.org/public/?cmd=freebusy&start=2010-10-27T05:00:00Z& end=2010-11-14T06:00:00Z&interval=15&u=dave.skor...@uwmidsouth.org

> > - Group Exchange
> > 2010-11-02 15:12:12,583 [12108] DEBUG
> > Google.GCalExchangeSync.Library.FreeBusyConverter - Parsing the raster
>

> > 444444444444444444444444444444444444444444444444444444444444444444444444444 444444444444444444444444444444444444444444444444444444444444444444444444444 444444444444444444444444444444444444444444444444444444444444444444444444444 444444444444444444444444444444444444444444444444444444444444444444444444444 444444444444444444444444444444444444444444444444444444444444444444444444444 444444444444444444444444444444444444444444444444444444444444444444444444444 444444444400000000000000000000000000000000000000000000000000000000000000000 000000000000000002222000000000000000000000000000000000000000000000000000000 000000000000000000000000000000222222000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000333 333300000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000222200000000000000000000000000000000000000000000000000000 000000000000000000000000000000000000000000000000000000000000000000000000000 000000000000000000000000000000222222000000000000000000000000000000000000033 333330000000000000033333333333333333333333333333333333333333333333333333333 333333333333333333333333333333333333333333333333333333333333333333333333333 333333333333333333333333333333333333333333333333333333333333333333333333333 333333333333333333333333333333333333333333333333333333333333333333333333333 3333333

> > 2010-11-02 15:12:12,583 [12108] DEBUG
> > Google.GCalExchangeSync.Library.FreeBusyConverter - Parsed the raster
> > into 4 busy and 0 tentative ranges
> > 2010-11-02 15:12:12,583 [12108] INFO
> > Google.GCalExchangeSync.Library.Util.BlockTimer - [Timer] -
> > LookupFreeBusyTimes - Total Execution Time: 16 ms.
> > 2010-11-02 15:12:12,583 [12108] INFO
> > Google.GCalExchangeSync.Library.ExchangeService - Busy: 4, Tentative:
> > 0, OOO: 3, All: 7
> > 2010-11-02 15:12:12,583 [12108] INFO
> > Google.GCalExchangeSync.Library.ExchangeService - Merge Result 7 -> 7
> > 2010-11-02 15:12:12,583 [12108] INFO
> > Google.GCalExchangeSync.Library.ExchangeService - Merged with 0
> > Appointments
> > 2010-11-02 15:12:12,583 [12108] INFO
> > Google.GCalExchangeSync.Library.Util.BlockTimer - [Timer] -
> > MergeFreeBusyWithAppointments - Total Execution Time: 0 ms.
> > 2010-11-02 15:12:12,583 [12108] DEBUG
> > Google.GCalExchangeSync.Library.ConfigCache - Mapping:

> > dave.skor...@uwmidsouth.org

> ...
>
> read more »

Richard Champlin

unread,

Nov 16, 2010, 4:39:35 PM11/16/10

to google-calendar-connectors

Just want to update this thread with the news that our issue(s) have
been successfully addressed through Google's assistance (Thanks,
Darrell!).

We are now going forward with our Pilot project, which will consist of
gradually migrating Exchange users to Google Apps in a mixed
environment.

Again, THANKS!

Richard

On Nov 3, 9:49 am, Richard Champlin <richard.champ...@uwmidsouth.org>
wrote:

> > >https://owa.uwmidsouth.org/public/?cmd=freebusy&start=2010-10-27T05:0...end=2010-11-14T06:00:00Z&interval=15&u=dave.skor...@uwmidsouth.org