View Issue Details

IDProjectCategoryView StatusLast Update
0001872SOGoOpenChange backendpublic2012-10-04 16:32
Reportergyurco Assigned Towsourdeau 
PrioritynormalSeveritycrashReproducibilityalways
Status resolvedResolutionfixed 
Target Version2.0.1Fixed in Version2.0.1 
Summary0001872: scalability: the sync process uses too much memory at once, leading to crashes with large mailboxes
Description

Samba4 always crashing when downloading INBOX at the first time:
Using latest nightly build (20120712) for CentOS 6.3
.
.
.
Jul 12 12:58:27 samba [14413]: <MAPIStoreMailMessage:0x2053898:(null)> -init
[SOGo: sogo_folder_open_message:479]
Jul 12 12:58:28 samba [14413]: <MAPIStoreMailMessage:0x214f478:(null)> -init
[SOGo: sogo_message_get_message_data:723]
[SOGo: sogo_message_get_attachment_table:819]
Jul 12 12:58:28 samba [14413]: <0x0x2ca6f08[MAPIStoreAttachmentTable]> -init
Jul 12 12:58:28 samba [14413]: <0x0x2ca6f08[MAPIStoreAttachmentTable]> -retain
Jul 12 12:58:28 samba [14413]: <0x0x2ca6f08[MAPIStoreAttachmentTable]> -release
[emsmdbp_object_destructor:666]: emsmdbp table object released
Jul 12 12:58:28 samba [14413]: <0x0x2ca6f08[MAPIStoreAttachmentTable]> -release
Jul 12 12:58:28 samba [14413]: <0x0x2ca6f08[MAPIStoreAttachmentTable]> -dealloc
[emsmdbp_object_destructor:666]: emsmdbp message object released
[SOGo: sogo_table_get_row:1131]
Jul 12 12:58:28 samba [14413]: <MAPIStoreMailMessage:0x2c1dbc8:(null)> -init
[SOGo: sogo_folder_open_message:479]
Jul 12 12:58:28 samba [14413]: <MAPIStoreMailMessage:0xc684a8:(null)> -init
[SOGo: sogo_message_get_message_data:723]
[SOGo: sogo_message_get_attachment_table:819]
Jul 12 12:58:28 samba [14413]: <0x0x955788[MAPIStoreAttachmentTable]> -init
Jul 12 12:58:28 samba [14413]: <0x0x955788[MAPIStoreAttachmentTable]> -retain
Jul 12 12:58:28 samba [14413]: <0x0x955788[MAPIStoreAttachmentTable]> -release
[emsmdbp_object_destructor:666]: emsmdbp table object released
Jul 12 12:58:28 samba [14413]: <0x0x955788[MAPIStoreAttachmentTable]> -release
Jul 12 12:58:28 samba [14413]: <0x0x955788[MAPIStoreAttachmentTable]> -dealloc
[emsmdbp_object_destructor:666]: emsmdbp message object released
[SOGo: sogo_table_get_row:1131]
Jul 12 12:58:28 samba [14413]: <MAPIStoreMailMessage:0x9594e8:(null)> -init
[SOGo: sogo_folder_open_message:479]
Jul 12 12:58:28 samba [14413]: <MAPIStoreMailMessage:0xb0f6a8:(null)> -init
[SOGo: sogo_message_get_message_data:723]
ndr_push_error(12): Failed to push_expand to 271387224

Program received signal SIGSEGV, Segmentation fault.
0x0000003b9960978e in ndr_push_uint32 (ndr=0x15c11f0, ndr_flags=<value optimized out>, v=1703967)
at ../librpc/ndr/ndr_basic.c:520
520 NDR_SIVAL(ndr, ndr->offset, v);

Backtrace with gdb:
#0 0x0000003b9960978e in ndr_push_uint32 (ndr=0x15c11f0, ndr_flags=<value optimized out>, v=1703967)
at ../librpc/ndr/ndr_basic.c:520
0000001 0x00007fffe9740ddc in oxcfxics_ndr_push_properties (ndr=0x15c11f0, cutmarks_ndr=0xfddc20, nprops_ctx=0xe7a3f0,
properties=0x7fffffffd6d0, data_pointers=0x1dbbbb8, retvals=0x1e278b4) at mapiproxy/servers/default/emsmdb/oxcfxics.c:194
0000002 0x00007fffe974205d in oxcfxics_push_messageChange (mem_ctx=0xdc4290, emsmdbp_ctx=0x197f570, synccontext=0x1812660,
owner=0xfabd00 "admin", sync_data=0xba5990, folder_object=0x94b9b0) at mapiproxy/servers/default/emsmdb/oxcfxics.c:785
0000003 0x00007fffe9744075 in oxcfxics_prepare_synccontext_with_messageChange (mem_ctx=0xdc4290,
emsmdbp_ctx=<value optimized out>, mapi_req=<value optimized out>, mapi_repl=0x3263db0, handles=<value optimized out>,
size=0x7fffffffd8be) at mapiproxy/servers/default/emsmdb/oxcfxics.c:860
0000004 EcDoRpc_RopFastTransferSourceGetBuffer (mem_ctx=0xdc4290, emsmdbp_ctx=<value optimized out>,
mapi_req=<value optimized out>, mapi_repl=0x3263db0, handles=<value optimized out>, size=0x7fffffffd8be)
at mapiproxy/servers/default/emsmdb/oxcfxics.c:1333
0000005 0x00007fffe972c518 in EcDoRpc_process_transaction (mem_ctx=0xdc4290, emsmdbp_ctx=0x197f570, mapi_request=0x2202e20)
at mapiproxy/servers/default/emsmdb/dcesrv_exchange_emsmdb.c:1028
0000006 0x00007fffe972cc84 in dcesrv_EcDoRpcExt2 (dce_call=<value optimized out>, mem_ctx=0xdc4290, r=0x1c43900)
at mapiproxy/servers/default/emsmdb/dcesrv_exchange_emsmdb.c:1743
0000007 0x00007fffe972d7de in dcesrv_exchange_emsmdb_dispatch (dce_call=0xdc4290, mem_ctx=0xdc4290, r=0x1c43900,
mapiproxy=<value optimized out>) at mapiproxy/servers/default/emsmdb/dcesrv_exchange_emsmdb.c:1904
0000008 0x00007fffea67e193 in mapiproxy_server_dispatch (dce_call=0xdc4290, mem_ctx=0xdc4290, r=0x1c43900,
mapiproxy=0x7fffffffda70) at mapiproxy/libmapiproxy/dcesrv_mapiproxy_server.c:57
0000009 0x00007fffea8bd80c in mapiproxy_op_dispatch (dce_call=0xdc4290, mem_ctx=0xdc4290, r=0x1c43900)
at mapiproxy/dcesrv_mapiproxy.c:497
0000010 0x0000003bb006cdf1 in dcesrv_request (dce_conn=<value optimized out>, pkt=<value optimized out>, blob=...)
at ../source4/rpc_server/dcerpc_server.c:965
0000011 dcesrv_process_ncacn_packet (dce_conn=<value optimized out>, pkt=<value optimized out>, blob=...)
at ../source4/rpc_server/dcerpc_server.c:1110
0000012 0x0000003bb006da79 in dcesrv_read_fragment_done (subreq=0x0) at ../source4/rpc_server/dcerpc_server.c:1488
0000013 0x0000003ba4810e58 in dcerpc_read_ncacn_packet_done (subreq=0x0) at ../librpc/rpc/dcerpc_util.c:295
0000014 0x0000003b9e80ab44 in tstream_readv_pdu_readv_done (subreq=0xfddc20) at ../lib/tsocket/tsocket_helpers.c:290
0000015 0x0000003b9e809b64 in tstream_readv_done (subreq=0x0) at ../lib/tsocket/tsocket.c:604
0000016 0x0000003b93e040f8 in tevent_common_loop_immediate (ev=0x630930) at ../tevent_immediate.c:135
0000017 0x0000003b93e0699a in std_event_loop_once (ev=0x630930, location=<value optimized out>) at ../tevent_standard.c:553
0000018 0x0000003b93e035b0 in _tevent_loop_once (ev=0x630930, location=0x40c339 "../source4/smbd/server.c:472")
at ../tevent.c:504
0000019 0x0000003b93e0361b in tevent_common_loop_wait (ev=0x630930, location=0x40c339 "../source4/smbd/server.c:472")
at ../tevent.c:605
0000020 0x0000000000409221 in binary_smbd_main (argc=<value optimized out>, argv=<value optimized out>,
binary_name=0x40c047 "samba") at ../source4/smbd/server.c:472
0000021 0x0000003b8e21ecdd in __libc_start_main () from /lib64/libc.so.6
0000022 0x00000000004055c9 in _start ()

TagsNo tags attached.

Activities

ludovic

ludovic

2012-08-16 14:44

administrator   ~0004341

Try again with the version that will be available next week.

ludovic

ludovic

2012-09-05 11:13

administrator   ~0004435

Try again with RC5 and reopen if necessary.

gyurco

gyurco

2012-09-21 07:43

reporter   ~0004528

Tried with latest nighly build (2.0_20120917), re-creted the samba domain, createad a brand new mailbox in Outlook 2007, dropped the socfs_admin table in postgres, still crashes. It's a big mailbox, with about 1 gigabytes of mail, if I reduce it to 50-60 megabytes, then the crash is gone.

[2012/09/21 13:47:24, 5] MAPIStoreSOGo.m:905(sogo_message_get_attachment_table)
[SOGo: sogo_message_get_attachment_table:905]
Sep 21 13:47:24 samba [29641]: <0x0x2474568[MAPIStoreAttachmentTable]> -init
Sep 21 13:47:24 samba [29641]: <0x0x2474568[MAPIStoreAttachmentTable]> -retain
Sep 21 13:47:24 samba [29641]: <0x0x2474568[MAPIStoreAttachmentTable]> -release
[2012/09/21 13:47:24, 4] mapiproxy/servers/default/emsmdb/emsmdbp_object.c:660(emsmdbp_object_destructor)
[emsmdbp_object_destructor:660]: emsmdbp table object released
Sep 21 13:47:24 samba [29641]: <0x0x2474568[MAPIStoreAttachmentTable]> -release
Sep 21 13:47:24 samba [29641]: <0x0x2474568[MAPIStoreAttachmentTable]> -dealloc
[2012/09/21 13:47:24, 4] mapiproxy/servers/default/emsmdb/emsmdbp_object.c:660(emsmdbp_object_destructor)
[emsmdbp_object_destructor:660]: emsmdbp message object released
[2012/09/21 13:47:24, 5] MAPIStoreSOGo.m:1253(sogo_table_get_row)
[SOGo: sogo_table_get_row:1253]
Sep 21 13:47:24 samba [29641]: <MAPIStoreMailMessage:0x20de0a8:(null)> -init
[2012/09/21 13:47:24, 5] MAPIStoreSOGo.m:479(sogo_folder_open_message)
[SOGo: sogo_folder_open_message:479]
Sep 21 13:47:24 samba [29641]: <MAPIStoreMailMessage:0x2f14b38:(null)> -init
[2012/09/21 13:47:24, 5] MAPIStoreSOGo.m:809(sogo_message_get_message_data)
[SOGo: sogo_message_get_message_data:809]
[2012/09/21 13:47:24, 1] ../librpc/ndr/ndr.c:438(ndr_push_error)
ndr_push_error(12): Failed to push_expand to 271436790

ludovic

ludovic

2012-09-24 15:08

administrator   ~0004535

Can you produce a stack trace?

gyurco

gyurco

2012-09-26 08:09

reporter   ~0004551

Seems not much difference from the previous version (20120926 runs now):

ndr_push_error(12): Failed to push_expand to 271431372

Program received signal SIGSEGV, Segmentation fault.
0x00007ffff669c63e in ndr_push_uint32 (ndr=0x21aa610, ndr_flags=<value optimized out>, v=1703967) at ../librpc/ndr/ndr_basic.c:520
520 NDR_SIVAL(ndr, ndr->offset, v);
(gdb) bt
#0 0x00007ffff669c63e in ndr_push_uint32 (ndr=0x21aa610, ndr_flags=<value optimized out>, v=1703967) at ../librpc/ndr/ndr_basic.c:520
0000001 0x00007fffdf513db0 in oxcfxics_ndr_push_properties (ndr=0x21aa610, cutmarks_ndr=0xf19d10, nprops_ctx=0x1862170, properties=0x7fffffffd6a0, data_pointers=0xa79928, retvals=0xfb033c)
at mapiproxy/servers/default/emsmdb/oxcfxics.c:272
0000002 0x00007fffdf515544 in oxcfxics_push_messageChange (mem_ctx=0xf197d0, emsmdbp_ctx=0x1d23c50, synccontext=0x25ce120, owner=0x27d3370 "admin", sync_data=0x1eae610, folder_object=0xd332e0)
at mapiproxy/servers/default/emsmdb/oxcfxics.c:957
0000003 0x00007fffdf5175fd in oxcfxics_prepare_synccontext_with_messageChange (mem_ctx=0xf197d0, emsmdbp_ctx=<value optimized out>, mapi_req=<value optimized out>, mapi_repl=0x31feae0,
handles=<value optimized out>, size=0x7fffffffd8ae) at mapiproxy/servers/default/emsmdb/oxcfxics.c:1032
0000004 EcDoRpc_RopFastTransferSourceGetBuffer (mem_ctx=0xf197d0, emsmdbp_ctx=<value optimized out>, mapi_req=<value optimized out>, mapi_repl=0x31feae0, handles=<value optimized out>, size=0x7fffffffd8ae)
at mapiproxy/servers/default/emsmdb/oxcfxics.c:1528
0000005 0x00007fffdf4fea58 in EcDoRpc_process_transaction (mem_ctx=0xf197d0, emsmdbp_ctx=0x1d23c50, mapi_request=0xc0d680) at mapiproxy/servers/default/emsmdb/dcesrv_exchange_emsmdb.c:1040
0000006 0x00007fffdf4ff224 in dcesrv_EcDoRpcExt2 (dce_call=<value optimized out>, mem_ctx=0xf197d0, r=0x20f2f20) at mapiproxy/servers/default/emsmdb/dcesrv_exchange_emsmdb.c:1755
0000007 0x00007fffdf4ffd7e in dcesrv_exchange_emsmdb_dispatch (dce_call=0xf197d0, mem_ctx=0xf197d0, r=0x20f2f20, mapiproxy=<value optimized out>) at mapiproxy/servers/default/emsmdb/dcesrv_exchange_emsmdb.c:1916
0000008 0x00007fffe04532a3 in mapiproxy_server_dispatch (dce_call=0xf197d0, mem_ctx=0xf197d0, r=0x20f2f20, mapiproxy=0x7fffffffda60) at mapiproxy/libmapiproxy/dcesrv_mapiproxy_server.c:57
0000009 0x00007fffe069298c in mapiproxy_op_dispatch (dce_call=0xf197d0, mem_ctx=0xf197d0, r=0x20f2f20) at mapiproxy/dcesrv_mapiproxy.c:497
0000010 0x00007fffea391022 in dcesrv_request (dce_conn=<value optimized out>, pkt=<value optimized out>, blob=...) at ../source4/rpc_server/dcerpc_server.c:965
0000011 dcesrv_process_ncacn_packet (dce_conn=<value optimized out>, pkt=<value optimized out>, blob=...) at ../source4/rpc_server/dcerpc_server.c:1110
0000012 0x00007fffea391c89 in dcesrv_read_fragment_done (subreq=0x0) at ../source4/rpc_server/dcerpc_server.c:1488
0000013 0x00007ffff4dab018 in dcerpc_read_ncacn_packet_done (subreq=0x0) at ../librpc/rpc/dcerpc_util.c:295
0000014 0x00007ffff255db24 in tstream_readv_pdu_readv_done (subreq=0x2641bb0) at ../lib/tsocket/tsocket_helpers.c:290
0000015 0x00007ffff255cb44 in tstream_readv_done (subreq=0x0) at ../lib/tsocket/tsocket.c:604
0000016 0x00007ffff475a358 in tevent_common_loop_immediate (ev=0x62eef0) at ../tevent_immediate.c:135
0000017 0x00007ffff475cc3a in std_event_loop_once (ev=0x62eef0, location=<value optimized out>) at ../tevent_standard.c:555
0000018 0x00007ffff4759790 in _tevent_loop_once (ev=0x62eef0, location=0x40bd99 "../source4/smbd/server.c:472") at ../tevent.c:506
0000019 0x00007ffff47597fb in tevent_common_loop_wait (ev=0x62eef0, location=0x40bd99 "../source4/smbd/server.c:472") at ../tevent.c:607
0000020 0x0000000000409031 in binary_smbd_main (argc=<value optimized out>, argv=<value optimized out>, binary_name=0x40baa7 "samba") at ../source4/smbd/server.c:472
0000021 0x0000003c11e1ecdd in __libc_start_main () from /lib64/libc.so.6
0000022 0x00000000004053f9 in _start ()

ludovic

ludovic

2012-09-26 08:50

administrator   ~0004556

Does the mailbox have many mails?

Perhaps there's a culprit mail in there that triggers this bug.

If it's a small mailbox, do you think we could have a copy for our own testing?

gyurco

gyurco

2012-09-26 10:09

reporter   ~0004563

It's a rather large one, with about 1 gigabytes of mail, I'll try to reduce it to the minimum which triggers the crash, then compress. Where should I send/upload the compressed file?

wsourdeau

wsourdeau

2012-09-26 15:11

viewer   ~0004572

This is expected for now as the synchronisation process puts everything in memory before sending it to the client. The code is quite complex already with that mechanism and I did not think at first that such large mailboxes would be used. This certainly can be fixed but it will require to keep a state of the synchronization between invocations of FastTransferGetBuffer.

gyurco

gyurco

2012-09-27 04:26

reporter   ~0004578

Ahh, that explains why it's not possible to pinpoint one mail which causes the crash. The limit (I guess it depends on the hardware, too) for me is about 200 MB for a folder.
Well, crashing is bad anyway, users cannot be tell that they shouldn't use such mailboxes...

wsourdeau

wsourdeau

2012-10-04 16:22

viewer   ~0004612

Solved in svn commit 4169

wsourdeau

wsourdeau

2012-10-04 16:32

viewer   ~0004613

gyurco: this should be solve, please give it a try with the next nigthlies if you can. Otherwise this will simply be part of 2.0.1

Issue History

Date Modified Username Field Change
2012-07-12 09:03 gyurco New Issue
2012-07-25 16:08 ludovic Target Version => 2.0
2012-08-16 14:44 ludovic Note Added: 0004341
2012-08-16 14:44 ludovic Product Version trunk =>
2012-08-16 14:44 ludovic Target Version 2.0 =>
2012-09-05 11:13 ludovic Note Added: 0004435
2012-09-05 11:13 ludovic Status new => closed
2012-09-05 11:13 ludovic Resolution open => unable to reproduce
2012-09-21 07:43 gyurco Note Added: 0004528
2012-09-21 07:43 gyurco Status closed => feedback
2012-09-21 07:43 gyurco Resolution unable to reproduce => reopened
2012-09-24 15:08 ludovic Note Added: 0004535
2012-09-26 08:09 gyurco Note Added: 0004551
2012-09-26 08:50 ludovic Note Added: 0004556
2012-09-26 10:09 gyurco Note Added: 0004563
2012-09-26 15:09 wsourdeau Summary Samba4 crashing when downloding INBOX => Samba4 crashing when downloding large mailboxes
2012-09-26 15:11 wsourdeau Note Added: 0004572
2012-09-27 04:26 gyurco Note Added: 0004578
2012-10-03 11:09 wsourdeau Project SOGo Native Outlook Compatibility (obsolete) => SOGo
2012-10-03 11:12 wsourdeau Category => OpenChange backend
2012-10-03 11:20 wsourdeau Summary Samba4 crashing when downloding large mailboxes => The sync process uses too much memory at once, leading to crashes with large mailboxes
2012-10-03 11:20 wsourdeau Target Version => 2.0.1
2012-10-03 11:31 wsourdeau Summary The sync process uses too much memory at once, leading to crashes with large mailboxes => scalability: the sync process uses too much memory at once, leading to crashes with large mailboxes
2012-10-03 13:05 wsourdeau Status feedback => assigned
2012-10-03 13:05 wsourdeau Assigned To => wsourdeau
2012-10-04 16:22 wsourdeau Note Added: 0004612
2012-10-04 16:22 wsourdeau Status assigned => resolved
2012-10-04 16:22 wsourdeau Fixed in Version => 2.0.1
2012-10-04 16:22 wsourdeau Resolution reopened => fixed
2012-10-04 16:32 wsourdeau Note Added: 0004613