Crash and subsequent savefile corruption

ID:2122875
 
Jul 27 2016, 6:21 pm
BYOND Version:510.1346
Operating System:Linux
Web Browser:Chrome 51.0.2704.103
Applies to:Dream Daemon
Status: Open
Issue hasn't been assigned a status value.
Descriptive Problem Summary:

[ Several tens of thousands of similar lines of "BUG:" ]
...
...
...

BUG: Bad ref (f:4630181) in DecRefCount(DM keymapping.dm:151)
BUG: Bad ref (f:4630181) in IncRefCount(DM keymapping.dm:151)
BUG: Bad ref (f:4630181) in DecRefCount(DM keymapping.dm:151)
BUG: Bad ref (f:4630181) in IncRefCount(DM keymapping.dm:151)
BUG: Bad ref (f:4630181) in DecRefCount(DM keymapping.dm:151)
BUG: Bad ref (f:4630181) in DecRefCount
BUG: Bad ref (f:4561055) in DecRefCount
BUG: Bad ref (f:4646475) in DecRefCount
BUG: Bad ref (f:4653090) in DecRefCount
BUG: Bad ref (f:4653091) in DecRefCount
BUG: Bad ref (f:4643525) in IncRefCount(DM _spell.dm:27)
BUG: Bad ref (f:4643525) in DecRefCount(DM _spell.dm:27)
BUG: Bad ref (f:4643546) in IncRefCount(DM _player.dm:374)
BUG: Bad ref (f:4643546) in DecRefCount(DM _player.dm:374)
BUG: Crashing due to an illegal operation!

Backtrace for BYOND 510.1346 on Linux:
Generated at Wed Jul 27 13:58:22 2016

DreamDaemon [0x8048000, 0x0], [0x8048000, 0x804bb24]
libbyond.so [0xf7269000, 0x0], 0x1ed3e8
 [0xf77b2000, 0xf77b2410], [0xf77b2000, 0xf77b2410]
libbyond.so [0xf7269000, 0x0], 0x1ed3e8
libbyond.so [0xf7269000, 0x0], 0x1eefcb
libbyond.so [0xf7269000, 0x0], 0x213a12
libbyond.so [0xf7269000, 0x0], 0x2151ae
libbyond.so [0xf7269000, 0x0], 0x215533
libbyond.so 0x32e770, 0x32e88a
libbyond.so 0x2f8600, 0x2f8802
DreamDaemon [0x8048000, 0x0], [0x8048000, 0x804ae34]
libc.so.6 0x16d60, 0x16e46 (__libc_start_main)
DreamDaemon [0x8048000, 0x0], [0x8048000, 0x804a731]

Recent proc calls:
/mob/player/proc/UnChannel
/mob/player/Logout
/client/proc/SaveKeymap
/client/Del
/mob/player/proc/UnChannel
/mob/player/Logout
/client/proc/SaveKeymap
/client/Del
/mob/player/proc/UnChannel
/mob/player/Logout
/client/proc/SaveKeymap
/client/Del
/mob/player/proc/UnChannel
/mob/player/Logout
/client/proc/SaveKeymap
/client/Del

To help the BYOND developers debug this, please send the above trace as part
of a very detailed bug report: http://www.byond.com/members/?command=view_tracker&tracker=1


At around Wed Jul 27 13:58:22 2016 (EST) our server at Eternia crashed with the above output. We've checked the relevant procs for errors on our part, but it all seems good.

As result of this crash, however, all players who were online at the time had their savefiles irreversibly corrupted. I was personally naive enough to neglect implementing a proper file backup system for a case like this, so now we have quite a few unhappy players!

The players with corrupted savefiles would log back in and generate errors much like this:
Wed Jul 27 15:23:59 2016
World opened on network port 5000.
Welcome BYOND! (5.0 Public Version 510.1346)
The BYOND hub reports that port 5000 is reachable.
BUG: Finished erasure with refcount=1 (ref=5:9) DM (keymapping.dm:170)
BUG: Bad ref (5:9) in DecRefCount(DM keymapping.dm:170)
BUG: Corrupt block header
BUG: Fmem block size at 1207 is 1174066936/120058 with type 81.
BUG: Error reading file memory structureFile offset: 1207
Real position: 1212/120058
BUG: Ccorrupt or invalid savefile 'saves/bindings/zeltzen4lyfe_bindings.sav'
BUG: Attempting auto-recovery of '/root/Eternia/saves/bindings/zeltzen4lyfe_bindings.sav'
BUG: Backed up old savefile as '/root/Eternia/saves/bindings/zeltzen4lyfe_bindings_bad_000.sav' and exported text to '/root/Eternia/saves/bindings/zeltzen4lyfe_bindings_bad_000.txt'.  REMOVE OR RENAME THESE FILES.  If too many of these files build up, auto-recovery will be disabled.



Any information on this would be extremely appreciated. We'd like to avoid a similar scenario.
Jul 27 2016, 8:03 pm
I don't think there's any info I can offer here. The bad refs probably started from whatever corruption actually set this off, but there's no info on that. The savefiles got messed up as a result of being touched while that corruption was in play.

The actual root cause is probably not discernable.
Jul 28 2016, 2:09 am
In response to Lummox JR
Shucks. Thanks, anyway. Something similar has happened a year or two back, but not as severe and widespread.

Only thing we can do (and have done) is implement automated file backups.
Jul 28 2016, 8:31 am
Very similar errors occure with in my game also,
BUG: Bad ref (3:122) in IncRefCount(DM Move)
BUG: Bad ref (3:122) in IncRefCount(DM Crossed)
BUG: Bad ref (3:122) in DecRefCount(DM Crossed)
BUG: Bad ref (3:122) in DecRefCount(DM Move)


But only happens after few days after dyn.rsc gets to about 15-20m size, and when it gets to about 30mb+ the game starts to move slow, the movement gets choppy, only solution to remove the dyn.rsc reboot the game, and then its all smooth again for few days.

We are getting those inc, dec ref counts alot more often now then we did with 509, with 509 back then we could get about 10 in 2 weeks period, with 510 we are getting 1k+ of em in 2 weeks.