#136 Re-authentication fails
Initial connection at startup to the OCS server works without trouble. Several(?) hours later, when I check the "buddy list", I see that the connection was dropped, apparently due to "authentication failure". Manually re-connecting also works. Filtering on "connection" in the "Debug Window" (the events at 04:25 are the dropped connection):
(18:45:21) connection: Connecting. gc = 0x21b7800
(18:45:22) proxy: Attempting connection to 67.239.247.175
(18:45:22) proxy: Connection in progress
(18:45:24) connection: Activating keepalive.
(18:46:24) proxy: Connection attempt failed: Error resolving Autodiscover.asg.com:
No address associated with hostname
(18:46:25) proxy: Attempting connection to 67.239.247.218
(18:46:25) proxy: Connection in progress
(04:25:43) connection: Connection error on 0x21b7800 (reason: 2 description: Authentication failed)
(04:25:43) connection: Disconnecting connection 0x21b7800
(04:25:43) connection: Deactivating keepalive.
(04:25:43) connection: Destroying connection 0x21b7800
(09:01:27) connection: Connecting. gc = 0x326e1b0
(09:01:29) proxy: Attempting connection to 67.239.247.175
(09:01:29) proxy: Connection in progress
(09:01:31) connection: Activating keepalive.
(09:02:32) proxy: Connection attempt failed: Error resolving Autodiscover.asg.com:
No address associated with hostname
(09:02:32) proxy: Attempting connection to 67.239.247.218
(09:02:32) proxy: Connection in progress
Without the filter, there is nothing else relevant. The 18:45 and 09:01 blocks are manual re-connects.
Will follow up with a debug log, later today (likely). Take this as a heads-up, in case there is something else you will need.
This is with a very recent build of the plugin (fetched from git at your request, for the last bug report), and Pidgin 2.7.3.
Sorry, I was wrong. The initial automatic connection at Pidgin startup also fails with "authentication failed".
Your log excerpt don't show the authentication method, but I'm assuming it is NTLM. Please make sure that you have commit d556a06c159eabc787c0f754cccdfc8df8b93e5d which fixes bug #2834758.
Closing as duplicate for now.
Looks as though you may be right. Pulled the latest via git, rebuilt, and the failure on the initial automatic connection is gone. Running Pidgin with a captured debug log, so if there is still a later failure, will have a log.
I committed that change only last week. Since then pidgin on my desktop has been online for 6 days, i.e. about 25 re-registrations without any authentication/invalid message signature errors.
I just did a little probability calculation. The error happened if one of the first 15 bytes of a 16 byte key was 0. That means that the chance of pidgin-sipe handling one key incorrectly is 1-(255/256)^15 ~ 5.7%. There are 4 keys and all of them have to be correct, so the probability of the error raises to 1-((255/256)^15)^4 ~ 21%. The original code (from Nov-2008 onwards) had only one key, but with the NTLM(v2) rework the error was "copy & pasted" to affect 4 keys. No wonder the error became much more likely with the new NTLM code :-)
I did eventually get the mid-session authentication failure, but I cannot add the log file to this ticket (because it is closed?). Do you want me to open a new ticket?
Note that my VPN connections (Windows instances running in VMs) also dropped around the same time, and could not be immediately be re-established.
(I am running Pidgin on the Ubuntu host.)
Debug log with mid-session authentication failure.
Attached the log with the mid-session authentication failure (at 13:10, manual re-connection at 13:39).
(Sigh) Make that 13:01 for the auth fail.
Seems that at some point re-registering fails. It looks like the code does not restart authentication in this case.
Your OCS has a very low re-register timeout of 600 seconds = 10 minutes. Does this always happen after 40 minutes, i.e. at the 4th re-register attempt?
I was mixing up re-register and re-authentication. The code uses a fixed re-authentication timeout of 8 hours - 5 minutes (=28500 seconds). Currently the code only does a re-authenticate on the timeout but *NOT* when the re-register is rejected with "Not authorized".
In your case it seems that re-authentication is required after 40 minutes or the 4th re-register attempt.
Please re-try with commit f41ea03.
Pulled and built the latest from git. Capturing a debug log now. May take several hours before a recurrence.
As to how the company OCS server is configured, I do not know.
It seems that 600 seconds as expire value in a REGISTER response is the default. So pidgin-sipe will send a new REGISTER every 10 minutes, also on our OCS.
But there is no corresponding "expiration" value for the re-authentication. My guess the 8 hours timeout was derived from experience or looking what the M$ client does. In your case it seems the server is configured differently. Let's wait and see if the new code helps.
Debug log of overnight with NO authentication failures (first 10K lines)
Well, that certainly seems to help. Left running overnight, and still connected in the morning.
Attached the first 10K lines of the log file, as the full log was too large to attach (even compressed).
While the first attempt fixed the problem for you, the changes caused other problems.
Please retry with git commit 2580b6f. I think I have been able to simulate your case and I'm pretty certain that it should still work for you.
Looking at your second log I can see that your OCS installation seems to reject re-REGISTER at random. This time it took 17 attempts before it failed, i.e. almost 3 hours.
Pulled the latest from git, and built. Pidgin is running, and a debug log is collecting. Will send in a log when enough(?) time has elapsed.
The be honest, I have very limited faith in the folk responsible for the company's Exchange / OCS installation. Would not be surprised if the configuration was odd.
Debug log of ~5 hours w/o apparent trouble.
Attached a debug log from this afternoon. (Had to use bzip2 to get under the SF upload limit.) Seems to have worked w/o trouble.