View Issue Details

Related ChangesetsJump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0005266SOGoActiveSyncpublic2021-02-22 16:032022-07-15 10:55
Reporterdanbet Assigned Toludovic  
PrioritynormalSeverityminorReproducibilityalways
Status resolvedResolutionfixed 
PlatformLinuxOSDebianOS Version10.9
Product Version5.0.1 
Fixed in Version5.1.0 
Summary0005266: S/MIME signed e-mails on ActiveSync
Description

I use Nine from 9Folders on Android to access my SOGo server using ActiveSync.

Every S/MIME signed e-mail is shown to me as incorrect with this error message: Unexpected error when receiving a SMIME message (1007). If I look at the same e-mail on my PC, the certificate details are correct.

I asked 9Folders support and they say me this: according to the log, you are using an Exchange clone server. What kind of server is it? Anyway, our developer reviewed your server, and your server doesn't seem to support the "Fetch" function. Due to this, the problem seems to occur.

Is it true? Can SOGo not fetch the certificate?

Steps To Reproduce

Open Nine
Tap an e-mail that is S/MIME signed
The e-mail is shown, after a second or two the error message 1007 is shown.

TagsNo tags attached.

Activities

tfu

tfu

2021-02-22 19:36

reporter   ~0015097

Can you please set SOGoEASDebugEnabled = YES; and provide sogo.log after reproducing the problem?
danbet

danbet

2021-02-23 17:18

reporter   ~0015099

Clearly I do it for you.

sogo-eas.log (12,683 bytes)    
Feb 23 18:09:52 sogod [29525]: version 5.0.1 -- starting
Feb 23 18:09:52 sogod [29525]: vmem size check enabled: shutting down app when vmem > 384 MB. Currently at 85 MB
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57be410[SOGoProductLoader]> SOGo products loaded from '/usr/lib/GNUstep/SOGo':
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57be410[SOGoProductLoader]>   ActiveSync.SOGo, AdministrationUI.SOGo, Appointments.SOGo, CommonUI.SOGo, Contacts.SOGo, ContactsUI.SOGo, MailPartViewers.SOGo, Mailer.SOGo, MailerUI.SOGo, MainUI.SOGo, PreferencesUI.SOGo, SchedulerUI.SOGo
Feb 23 18:09:52 sogod [29525]: All products loaded - current memory usage at 98 MB
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> listening on *:30000
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> watchdog process pid: 29525
Feb 23 18:09:52 sogod [29525]: <0x0x7f0fe35a9360[WOWatchDogChild]> watchdog request timeout set to 10 minutes
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> preparing 15 children
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29526
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29527
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29528
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29529
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29530
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29531
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29532
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29533
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29534
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29535
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29536
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29537
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29538
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29539
Feb 23 18:09:52 sogod [29525]: <0x0x5560b57f8090[WOWatchDog]> child spawned with pid 29540
Feb 23 18:09:53 sogod [29527]: <0x0x5560b58ac1d0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29531]: <0x0x5560b58ac1d0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29526]: <0x0x5560b586ecb0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29528]: <0x0x5560b5995fa0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29529]: <0x0x5560b592efc0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29530]: <0x0x5560b58766e0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29533]: <0x0x5560b58766e0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29532]: <0x0x5560b586ecb0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29536]: <0x0x5560b597fa80[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29537]: <0x0x5560b59481a0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29535]: <0x0x5560b5825a00[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29534]: <0x0x5560b58766e0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29538]: <0x0x5560b59481a0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29539]: <0x0x5560b592efc0[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:09:53 sogod [29540]: <0x0x5560b5a16440[WOHttpAdaptor]> notified the watchdog that we are ready
Feb 23 18:10:31 sogod [29540]: <0x0x5560b58049a0[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Feb 23 18:10:31 sogod [29540]: <0x0x5560b58049a0[SOGoCache]> Using host(s) '127.0.0.1' as server(s)
Feb 23 18:10:31 sogod [29540]: <0x0x5560b55f5e80[SOGoActiveSyncDispatcher]> EAS - request for device 4E696E65443939453235423336463046: <?xml version="1.0"?>
<!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "http://www.microsoft.com/">
<Sync xmlns="AirSync:">
 <Collections>
  <Collection>
   <SyncKey>4109-15135</SyncKey>
   <CollectionId>mail%2Fd302540c3bb4b25460410000c2b7a16c</CollectionId>
   <DeletesAsMoves>1</DeletesAsMoves>
   <GetChanges>1</GetChanges>
   <WindowSize>10</WindowSize>
   <Options>
    <FilterType>0</FilterType>
    <BodyPreference xmlns="AirSyncBase:">
     <Type>2</Type>
     <TruncationSize>51200</TruncationSize>
    </BodyPreference>
    <Class>SMS</Class>
   </Options>
   <Options>
    <FilterType>0</FilterType>
    <Conflict>1</Conflict>
    <MIMETruncation>6</MIMETruncation>
    <MIMESupport>2</MIMESupport>
    <BodyPreference xmlns="AirSyncBase:">
     <Type>4</Type>
     <TruncationSize>51200</TruncationSize>
     <AllOrNone>0</AllOrNone>
    </BodyPreference>
   </Options>
  </Collection>
 </Collections>
</Sync>

Feb 23 18:10:31 sogod [29540]: <0x0x5560b56706e0[NGImap4Client]> TLS started successfully.
Feb 23 18:10:32 sogod [29540]: 84.254.91.175 "POST /SOGo/Microsoft-Server-ActiveSync?jQAJBBBOaW5lRDk5RTI1QjM2RjBGBAAAAAAHQW5kcm9pZAcBAA== HTTP/1.1" 200 0/162 0.700 - - 10M - 13
Feb 23 18:10:34 sogod [29540]: <0x0x5560b5c88620[SOGoActiveSyncDispatcher]> EAS - request for device 4E696E65443939453235423336463046: <?xml version="1.0"?>
<!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "http://www.microsoft.com/">
<Ping xmlns="Ping:">
 <HeartbeatInterval>840</HeartbeatInterval>
 <Folders>
  <Folder>
   <Id>mail%2Fd302540c3bb4b25460410000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2Fd602540c3bb4b25460410000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F0a725b01ecf826578c110000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F0303540c3bb4b25460410000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F42eeb928cd80be5e882e0000039af313</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F0703540c3bb4b25460410000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F2708920300e9d55adb110000039af313</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F5667301db1587c590d4900000353982d</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F7018e702b43c2358192900000353982d</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2Ff90e61175e50de588c4a00000353982d</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>vevent%2Fpersonal</Id>
   <Class>Calendar</Class>
  </Folder>
  <Folder>
   <Id>vtodo%2Fpersonal</Id>
   <Class>Tasks</Class>
  </Folder>
  <Folder>
   <Id>vcard%2Fpersonal</Id>
   <Class>Contacts</Class>
  </Folder>
 </Folders>
</Ping>

Feb 23 18:10:34 sogod [29540]: <0x0x5560b5a90ba0[NGImap4Client]> TLS started successfully.
Feb 23 18:10:36 sogod [29540]: [WARN] <0x0x5560b622bce0[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table
Feb 23 18:10:36 sogod [29540]: [WARN] <0x0x5560b622bce0[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table
Feb 23 18:10:36 sogod [29540]: [WARN] <0x0x5560b622bce0[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table
Feb 23 18:10:36 sogod [29540]: <0x0x5560b5c88620[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user daniel in Ping...
Feb 23 18:10:42 sogod [29539]: <0x0x5560b57a1ba0[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Feb 23 18:10:42 sogod [29539]: <0x0x5560b57a1ba0[SOGoCache]> Using host(s) '127.0.0.1' as server(s)
Feb 23 18:10:42 sogod [29539]: <0x0x5560b5997550[SOGoActiveSyncDispatcher]> EAS - request for device 4E696E65443939453235423336463046: <?xml version="1.0"?>
<!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "http://www.microsoft.com/">
<ItemOperations xmlns="ItemOperations:">
 <Fetch>
  <Store>Mailbox</Store>
  <CollectionId xmlns="AirSync:">mail%2Fd302540c3bb4b25460410000c2b7a16c</CollectionId>
  <ServerId xmlns="AirSync:">3942</ServerId>
  <Options>
   <MIMESupport xmlns="AirSync:">2</MIMESupport>
   <BodyPreference xmlns="AirSyncBase:">
    <Type>4</Type>
    <AllOrNone>0</AllOrNone>
   </BodyPreference>
  </Options>
 </Fetch>
</ItemOperations>

Feb 23 18:10:42 sogod [29539]: <0x0x5560b5996300[NGImap4Client]> TLS started successfully.
Feb 23 18:10:43 sogod [29539]: 84.254.91.175 "POST /SOGo/Microsoft-Server-ActiveSync?jRMJBBBOaW5lRDk5RTI1QjM2RjBGBAAAAAAHQW5kcm9pZAcBAA== HTTP/1.1" 200 9871/99 0.847 - - 9M - 12
Feb 23 18:10:44 sogod [29539]: <0x0x5560b55a66a0[SOGoActiveSyncDispatcher]> EAS - request for device 4E696E65443939453235423336463046: <?xml version="1.0"?>
<!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "http://www.microsoft.com/">
<ItemOperations xmlns="ItemOperations:">
 <Fetch>
  <Store>Mailbox</Store>
  <CollectionId xmlns="AirSync:">mail%2Fd302540c3bb4b25460410000c2b7a16c</CollectionId>
  <ServerId xmlns="AirSync:">3942</ServerId>
  <Options>
   <MIMESupport xmlns="AirSync:">2</MIMESupport>
   <BodyPreference xmlns="AirSyncBase:">
    <Type>4</Type>
    <AllOrNone>0</AllOrNone>
   </BodyPreference>
  </Options>
 </Fetch>
</ItemOperations>

Feb 23 18:10:44 sogod [29539]: <0x0x5560b595ca60[NGImap4Client]> TLS started successfully.
Feb 23 18:10:44 sogod [29539]: 84.254.91.175 "POST /SOGo/Microsoft-Server-ActiveSync?jRMJBBBOaW5lRDk5RTI1QjM2RjBGBAAAAAAHQW5kcm9pZAcBAA== HTTP/1.1" 200 9871/99 0.823 - - 112K - 12
Feb 23 18:10:45 sogod [29539]: <0x0x5560b5d8b2d0[SOGoActiveSyncDispatcher]> EAS - request for device 4E696E65443939453235423336463046: <?xml version="1.0"?>
<!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "http://www.microsoft.com/">
<Ping xmlns="Ping:">
 <HeartbeatInterval>840</HeartbeatInterval>
 <Folders>
  <Folder>
   <Id>mail%2Fd302540c3bb4b25460410000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2Fd602540c3bb4b25460410000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F0a725b01ecf826578c110000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F0303540c3bb4b25460410000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F42eeb928cd80be5e882e0000039af313</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F0703540c3bb4b25460410000c2b7a16c</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F2708920300e9d55adb110000039af313</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F5667301db1587c590d4900000353982d</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2F7018e702b43c2358192900000353982d</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>mail%2Ff90e61175e50de588c4a00000353982d</Id>
   <Class>Email</Class>
  </Folder>
  <Folder>
   <Id>vevent%2Fpersonal</Id>
   <Class>Calendar</Class>
  </Folder>
  <Folder>
   <Id>vtodo%2Fpersonal</Id>
   <Class>Tasks</Class>
  </Folder>
  <Folder>
   <Id>vcard%2Fpersonal</Id>
   <Class>Contacts</Class>
  </Folder>
 </Folders>
</Ping>

Feb 23 18:10:45 sogod [29539]: <0x0x5560b5c945e0[NGImap4Client]> TLS started successfully.
Feb 23 18:10:47 sogod [29539]: [WARN] <0x0x5560b625efa0[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table
Feb 23 18:10:47 sogod [29539]: [WARN] <0x0x5560b625efa0[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table
Feb 23 18:10:47 sogod [29539]: [WARN] <0x0x5560b625efa0[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table
Feb 23 18:10:47 sogod [29539]: <0x0x5560b5d8b2d0[SOGoActiveSyncDispatcher]> Sleeping 30 seconds while detecting changes for user daniel in Ping...
Feb 23 18:11:07 sogod [29540]: <0x0x5560b5c88620[SOGoActiveSyncDispatcher]> EAS - Ping request canceled (29539)
Feb 23 18:11:07 sogod [29540]: <0x0x5560b5c88620[SOGoActiveSyncDispatcher]> EAS - response for device 4E696E65443939453235423336463046: <?xml version="1.0"?>
<!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "http://www.microsoft.com/">
<Ping xmlns="Ping:">
 <Status>1</Status>
</Ping>

Feb 23 18:11:08 sogod [29540]: 84.254.91.175 "POST /SOGo/Microsoft-Server-ActiveSync?jRIJBBBOaW5lRDk5RTI1QjM2RjBGBAAAAAAHQW5kcm9pZAcBAA== HTTP/1.1" 200 13/657 33.119 - - 6M - 12
sogo-eas.log (12,683 bytes)   
tfu

tfu

2021-02-24 19:48

reporter   ~0015103

Can you please provide a sample mail in raw format?
danbet

danbet

2021-02-25 13:35

reporter   ~0015105

I will do my best, althouth for me it is not clear what do you mean with raw format.

test.eml (6,100 bytes)
tfu

tfu

2021-02-28 14:10

reporter   ~0015109

I identified the problem.
The response to a fetch-request was in multipart format by mistake.
Problem is caused by mis-interpreation of the base64-encoded query value.
Christian Mack

Christian Mack

2022-07-15 07:12

developer   ~0016128

got this fix merged with a SOGo release version?
danbet

danbet

2022-07-15 07:29

reporter   ~0016130

This is fixed since 5.1.0.

Related Changesets

sogo: master b2008cd3

2021-02-28 08:49

root


Details Diff		 fix(eas): improve EAS parameters parsing (fixes 0005266) Affected Issues
0005266
mod - ActiveSync/NSString+ActiveSync.m Diff File

sogo: master 080f87c5

2021-03-01 08:09

ludovic

Committer: GitHub


Details Diff		 Merge pull request #295 from tfux/5266

fix(eas): improve EAS parameters parsing (fixes 0005266)		 Affected Issues
0005266
mod - ActiveSync/NSString+ActiveSync.m Diff File

Issue History

Date Modified Username Field Change
2021-02-22 16:03 danbet New Issue
2021-02-22 19:36 tfu Note Added: 0015097
2021-02-23 17:18 danbet Note Added: 0015099
2021-02-23 17:18 danbet File Added: sogo-eas.log
2021-02-24 19:48 tfu Note Added: 0015103
2021-02-25 13:35 danbet Note Added: 0015105
2021-02-25 13:35 danbet File Added: test.eml
2021-02-28 14:10 tfu Note Added: 0015109
2021-03-01 13:09 Changeset attached => sogo master b2008cd3
2021-03-01 13:09 ludovic Changeset attached => sogo master 080f87c5
2021-03-01 13:09 ludovic Assigned To => ludovic
2021-03-01 13:09 ludovic Resolution open => fixed
2022-07-15 07:12 Christian Mack Note Added: 0016128
2022-07-15 07:29 danbet Note Added: 0016130
2022-07-15 10:55 francis Status new => resolved
2022-07-15 10:55 francis Fixed in Version => 5.1.0