Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Corrupt $DLG_end_reason #489

Closed
digipigeon opened this issue Apr 30, 2015 · 9 comments
Closed

Corrupt $DLG_end_reason #489

digipigeon opened this issue Apr 30, 2015 · 9 comments
Assignees
@bogdan-iancu
Labels
bug
Milestone
2.1.4

Comments

@digipigeon
Copy link

After upgrading to 2.1 the $DLG_end_reason variable does not behave correctly, e.g

Instead of receiving Upstream BYE or Downstream BYE, the following have been observed:

_QIofalzca3BYE
as6d72287aYE
as6d8a1de36BYE
as172d526d BYE
as217299fb BYE
nVrhXc31g8eBYE
as217299fb BYE
as6213fd80 BYE
as457d4de4 BYE
as6213fd80 BYE
as6d103339 BYE
as3bf8833deBYE
Upstream BYEYE
as67a55fd9 BYE
as55cefbb5 BYE
as457d4de4 BYE
as6d72287aYE
as172d526d BYE
Upstream BYEYE
@vladpaiu
Copy link
Member

vladpaiu commented May 1, 2015

Hello,

Looks like a memory corruption - I have not been able to reproduce this on my end.
Can you please let me know how you are able to reproduce this ? If it is happening randomly, then please enable memory debugging ( see http://www.opensips.org/Documentation/TroubleShooting-OutOfMem , the 'make menuconfig' part ) - this should lead to OpenSIPS generating a core dump when the buffer overflow is occuring.

Best Regards,
Vlad

@vladpaiu vladpaiu added the bug label May 1, 2015
@vladpaiu vladpaiu added this to the 2.1 milestone May 1, 2015
@vladpaiu vladpaiu self-assigned this May 1, 2015
@digipigeon
Copy link
Author

I have recompiled with DBG_QM_MALLOC and memlog=1, however now Opensips crashes on startup, I am not sure if this is related or not, but here is the information anyway:

May  4 12:52:35 [12500] WARNING:core:utimer_ticker: utimer task <tm-utimer> already schedualed for 2770 ms (now 2870 ms), it may overlap..
May  4 12:52:35 [12498] INFO:rtpengine:rtpe_test: rtp proxy <udp:162.243.XXX.XXX:12222> found, support for it enabled
May  4 12:52:35 [12498] WARNING:core:fm_malloc: Not enough free memory, will attempt defragmentation
May  4 12:52:35 [12498] ERROR:httpd:httpd_proc: oom
*   Trying 37.59.XXX.XXX...
May  4 12:52:35 [12489] INFO:core:handle_sigs: child process 12498 exited normally, status=0
May  4 12:52:35 [12489] INFO:core:handle_sigs: terminating due to SIGCHLD
May  4 12:52:35 [12495] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f60d37d7010):
 heap size= 2097152
 used= 478232, used+overhead=596456, free=1618920
 max used (+overhead)= 596456
dumping free list:
hash =  44 fragments no.:     1, unused:     0
                 bucket size:       352 -       352 (first       352)
hash =  67 fragments no.:     1, unused:     0
                 bucket size:       536 -       536 (first       536)
hash = 2055 fragments no.:     1, unused:     0
                 bucket size:   1048576 -   2097152 (first   1499808)
TOTAL:      3 free fragments = 1500696 free bytes
TOTAL: 1499808 large bytes
TOTAL: 24 overhead
-----------------------------
May  4 12:52:35 [12496] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f60d37d7010):
 heap size= 2097152
 used= 410632, used+overhead=528496, free=1686520
 max used (+overhead)= 529568
dumping free list:
hash =   3 fragments no.:     2, unused:     0
                 bucket size:        24 -        24 (first        24)
hash =   9 fragments no.:     2, unused:     0
                 bucket size:        72 -        72 (first        72)
hash =  67 fragments no.:     2, unused:     0
                 bucket size:       536 -       536 (first       536)
hash = 2055 fragments no.:     1, unused:     0
                 bucket size:   1048576 -   2097152 (first   1567392)
TOTAL:      7 free fragments = 1568656 free bytes
TOTAL: 1567392 large bytes
TOTAL: 24 overhead
-----------------------------
May  4 12:52:35 [12497] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f60d37d7010):
 heap size= 2097152
 used= 407992, used+overhead=524992, free=1689160
 max used (+overhead)= 524992
dumping free list:
hash = 2055 fragments no.:     1, unused:     0
                 bucket size:   1048576 -   2097152 (first   1572160)
TOTAL:      1 free fragments = 1572160 free bytes
TOTAL: 1572160 large bytes
TOTAL: 24 overhead
-----------------------------
May  4 12:52:35 [12499] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f60d37d7010):
 heap size= 2097152
 used= 407992, used+overhead=524992, free=1689160
 max used (+overhead)= 524992
dumping free list:
hash = 2055 fragments no.:     1, unused:     0
                 bucket size:   1048576 -   2097152 (first   1572160)
TOTAL:      1 free fragments = 1572160 free bytes
TOTAL: 1572160 large bytes
TOTAL: 24 overhead
-----------------------------
May  4 12:52:35 [12500] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f60d37d7010):
 heap size= 2097152
 used= 407992, used+overhead=524992, free=1689160
 max used (+overhead)= 524992
dumping free list:
hash = 2055 fragments no.:     1, unused:     0
                 bucket size:   1048576 -   2097152 (first   1572160)
TOTAL:      1 free fragments = 1572160 free bytes
TOTAL: 1572160 large bytes
TOTAL: 24 overhead
-----------------------------
May  4 12:52:35 [12489] INFO:core:cleanup: cleanup
May  4 12:52:35 [12489] NOTICE:dns_cache:destroy: destroy module dns_cache ...
May  4 12:52:35 [12489] NOTICE:event_rabbitmq:destroy: destroy module ...
May  4 12:52:35 [12489] NOTICE:cachedb_memcached:destroy: destroy module cachedb_redis ...
Memory status (pkg):
fm_status (0x7f60d37d7010):
 heap size= 2097152
 used= 417504, used+overhead=535728, free=1679648
 max used (+overhead)= 540072
dumping free list:
hash =   1 fragments no.:     2, unused:     0
                 bucket size:         8 -         8 (first         8)
hash =   2 fragments no.:     1, unused:     0
                 bucket size:        16 -        16 (first        16)
hash =   4 fragments no.:     6, unused:     0
                 bucket size:        32 -        32 (first        32)
hash =   5 fragments no.:     4, unused:     0
                 bucket size:        40 -        40 (first        40)
hash =   6 fragments no.:    36, unused:     0
                 bucket size:        48 -        48 (first        48)
hash =   7 fragments no.:     4, unused:     0
                 bucket size:        56 -        56 (first        56)
hash =   9 fragments no.:     2, unused:     0
                 bucket size:        72 -        72 (first        72)
hash =  10 fragments no.:    20, unused:     0
                 bucket size:        80 -        80 (first        80)
hash =  14 fragments no.:     1, unused:     0
                 bucket size:       112 -       112 (first       112)
hash =  19 fragments no.:     1, unused:     0
                 bucket size:       152 -       152 (first       152)
hash =  57 fragments no.:     1, unused:     0
                 bucket size:       456 -       456 (first       456)
hash =  67 fragments no.:     1, unused:     0
                 bucket size:       536 -       536 (first       536)
hash = 494 fragments no.:     1, unused:     0
                 bucket size:      3952 -      3952 (first      3952)
hash = 2055 fragments no.:     1, unused:     0
                 bucket size:   1048576 -   2097152 (first   1552136)
TOTAL:     81 free fragments = 1561424 free bytes
TOTAL: 1552136 large bytes
TOTAL: 24 overhead
-----------------------------
Memory status (shm):
fm_status (0x7f60c707e000):
 heap size= 33554432
 used= 2200, used+overhead=48136, free=33552232
 max used (+overhead)= 2881584
dumping free list:
hash =   1 fragments no.:    57, unused:     0
                 bucket size:         8 -         8 (first         8)
hash =   2 fragments no.:    50, unused:     0
                 bucket size:        16 -        16 (first        16)
hash =   3 fragments no.:    44, unused:     0
                 bucket size:        24 -        24 (first        24)
hash =   4 fragments no.:   103, unused:     0
                 bucket size:        32 -        32 (first        32)
hash =   5 fragments no.:     3, unused:     0
                 bucket size:        40 -        40 (first        40)
hash =   6 fragments no.:    10, unused:     0
                 bucket size:        48 -        48 (first        48)
hash =   8 fragments no.:    42, unused:     0
                 bucket size:        64 -        64 (first        64)
hash =   9 fragments no.:    56, unused:     0
                 bucket size:        72 -        72 (first        72)
hash =  10 fragments no.:    58, unused:     0
                 bucket size:        80 -        80 (first        80)
hash =  11 fragments no.:     2, unused:     0
                 bucket size:        88 -        88 (first        88)
hash =  13 fragments no.:     1, unused:     0
                 bucket size:       104 -       104 (first       104)
hash =  16 fragments no.:     1, unused:     0
                 bucket size:       128 -       128 (first       128)
hash =  17 fragments no.:     1, unused:     0
                 bucket size:       136 -       136 (first       136)
hash =  20 fragments no.:     1, unused:     0
                 bucket size:       160 -       160 (first       160)
hash =  23 fragments no.:     1, unused:     0
                 bucket size:       184 -       184 (first       184)
hash =  25 fragments no.:     4, unused:     0
                 bucket size:       200 -       200 (first       200)
hash =  26 fragments no.:     1, unused:     0
                 bucket size:       208 -       208 (first       208)
hash =  31 fragments no.:     1, unused:     0
                 bucket size:       248 -       248 (first       248)
hash =  41 fragments no.:     1, unused:     0
                 bucket size:       328 -       328 (first       328)
hash =  50 fragments no.:     1, unused:     0
                 bucket size:       400 -       400 (first       400)
hash =  67 fragments no.:     1, unused:     0
                 bucket size:       536 -       536 (first       536)
hash =  74 fragments no.:     1, unused:     0
                 bucket size:       592 -       592 (first       592)
hash = 112 fragments no.:     1, unused:     0
                 bucket size:       896 -       896 (first       896)
hash = 121 fragments no.:    13, unused:     0
                 bucket size:       968 -       968 (first       968)
hash = 122 fragments no.:     5, unused:     0
                 bucket size:       976 -       976 (first       976)
hash = 123 fragments no.:     1, unused:     0
                 bucket size:       984 -       984 (first       984)
hash = 124 fragments no.:     1, unused:     0
                 bucket size:       992 -       992 (first       992)
hash = 125 fragments no.:     1, unused:     0
                 bucket size:      1000 -      1000 (first      1000)
hash = 127 fragments no.:     1, unused:     0
                 bucket size:      1016 -      1016 (first      1016)
hash = 130 fragments no.:     1, unused:     0
                 bucket size:      1040 -      1040 (first      1040)
hash = 140 fragments no.:     1, unused:     0
                 bucket size:      1120 -      1120 (first      1120)
hash = 224 fragments no.:     1, unused:     0
                 bucket size:      1792 -      1792 (first      1792)
hash = 515 fragments no.:     1, unused:     0
                 bucket size:      4120 -      4120 (first      4120)
hash = 1024 fragments no.:     1, unused:     0
                 bucket size:      8192 -      8192 (first      8192)
hash = 1026 fragments no.:     1, unused:     0
                 bucket size:      8208 -      8208 (first      8208)
hash = 1563 fragments no.:     1, unused:     0
                 bucket size:     12504 -     12504 (first     12504)
hash = 2052 fragments no.:     1, unused:     0
                 bucket size:    131072 -    262144 (first    131104)
hash = 2056 fragments no.:     1, unused:     0
                 bucket size:   2097152 -   4194304 (first   2621448)
hash = 2059 fragments no.:     1, unused:     0
                 bucket size:  16777216 -  33554432 (first  30672848)
TOTAL:    473 free fragments = 33506296 free bytes
TOTAL: 33425400 large bytes
TOTAL: 24 overhead
-----------------------------

@digipigeon
Copy link
Author

Also:

May  4 15:21:24 [23072] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f7c7ab1d010):
 heap size= 524288000
 used= 423120, used+overhead=540432, free=523864880
 max used (+overhead)= 540432
dumping free list:
hash =  25 fragments no.:     1, unused:     0
                 bucket size:       200 -       200 (first       200)
hash =  67 fragments no.:     2, unused:     0
                 bucket size:       536 -       536 (first       536)
hash = 2063 fragments no.:     1, unused:     0
                 bucket size: 268435456 - 536870912 (first 523746296)
TOTAL:      4 free fragments = 523747568 free bytes
TOTAL: 523746296 large bytes
TOTAL: 24 overhead
-----------------------------
May  4 15:21:24 [23074] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f7c7ab1d010):
 heap size= 524288000
 used= 393621960, used+overhead=393739224, free=130666040
 max used (+overhead)= 393739224
dumping free list:
hash =  61 fragments no.:     1, unused:     0
                 bucket size:       488 -       488 (first       488)
hash =  67 fragments no.:     1, unused:     0
                 bucket size:       536 -       536 (first       536)
hash = 2061 fragments no.:     1, unused:     0
                 bucket size:  67108864 - 134217728 (first 130547752)
TOTAL:      3 free fragments = 130548776 free bytes
TOTAL: 130547752 large bytes
TOTAL: 24 overhead
-----------------------------
May  4 15:21:24 [23076] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f7c7ab1d010):
 heap size= 524288000
 used= 402320, used+overhead=518576, free=523885680
 max used (+overhead)= 518576
dumping free list:
hash = 2063 fragments no.:     1, unused:     0
                 bucket size: 268435456 - 536870912 (first 523769424)
TOTAL:      1 free fragments = 523769424 free bytes
TOTAL: 523769424 large bytes
TOTAL: 24 overhead
-----------------------------
May  4 15:21:24 [23075] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f7c7ab1d010):
 heap size= 524288000
 used= 402320, used+overhead=518576, free=523885680
 max used (+overhead)= 518576
dumping free list:
hash = 2063 fragments no.:     1, unused:     0
                 bucket size: 268435456 - 536870912 (first 523769424)
TOTAL:      1 free fragments = 523769424 free bytes
TOTAL: 523769424 large bytes
TOTAL: 24 overhead
-----------------------------
May  4 15:21:24 [23073] INFO:core:sig_usr: signal 15 received
Memory status (pkg):
fm_status (0x7f7c7ab1d010):
 heap size= 524288000
 used= 402320, used+overhead=518576, free=523885680
 max used (+overhead)= 518576
dumping free list:
hash = 2063 fragments no.:     1, unused:     0
                 bucket size: 268435456 - 536870912 (first 523769424)
TOTAL:      1 free fragments = 523769424 free bytes
TOTAL: 523769424 large bytes
TOTAL: 24 overhead
-----------------------------
Segmentation fault

@vladpaiu
Copy link
Member

vladpaiu commented May 7, 2015

Hello,

When running with DBG_QM_MALLOC, OpenSIPS will use more memory ( from your logs the HTTPD module does not have enough memory to start ) - so please increase the SHM and PKG values.
This way OpenSIPS should successfully start - afterwards replicate your scenario and hopefully OpenSIPS should crash. Send us the backtrace from the core file.

Best Regards,
Vlad

@digipigeon
Copy link
Author

I have a 1GB machine and set SHM & PKG to 400MB with 1 process running and it still crashes.

@digipigeon
Copy link
Author

Just for the record, I have tested the 2.1.1 stable version and this problem is still happening after only a few (less than 100) calls.

@bogdan-iancu
Copy link
Member

Hi @digipigeon ! How easy is to reproduce this? can you do it in reliable way ?

Also, where in the script do you access the $DLG_end_reason ?

@bogdan-iancu
Copy link
Member

@digipigeon , any update here - is the latest 2.1 and 2.2 still suffering from this problem ?

Also, a tricky question - where in the script do you use the $DLG_end_reason variable ? maybe the context of the dialog does not existing anymore when you try to access the variable.

@digipigeon
Copy link
Author

This problem is no longer present in 2.2

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@bogdan-iancu bogdan-iancu

Labels
bug
Projects
None yet
Milestone
2.1.4
Development

No branches or pull requests
3 participants
@digipigeon @vladpaiu @bogdan-iancu