is this necessarily a bad thing?

Nathan Smith

unread,

Dec 7, 2018, 9:12:17 PM12/7/18

to MOO Talk

Hello!

So I have been recently tinkering, getting stunt all nice and patched up with scattered for, subsecond fork, matching object, and handle argstr.

I booted up my core and then shut it down, as a test, this was the log.

Is this bad, or just stunt being... different.

If it is bad, what is wrong, and where should I look about fixing.

Log below.

Much thanks.

Nate

Dec 7 19:06:13: _____ ______

Dec 7 19:06:13: ___________ /_____ _________ __ /_

Dec 7 19:06:13: __ ___/_ __/_ / / /__ __ \_ __/

Dec 7 19:06:13: _(__ ) / /_ / /_/ / _ / / // /_

Dec 7 19:06:13: /____/ \__/ \__,_/ /_/ /_/ \__/

Dec 7 19:06:13:

Dec 7 19:06:13: CMDLINE: Initial port = 8000

Dec 7 19:06:13: CMDLINE: Outbound network connections enabled.

Dec 7 19:06:13: STARTING: Version 1.8.3+?_ad_hoc_?? of the Stunt/LambdaMOO server

Dec 7 19:06:13: (Using BSD/TCP protocol)

Dec 7 19:06:13: (Task timeouts measured in server CPU seconds.)

Dec 7 19:06:13: (Process id 12334)

Dec 7 19:06:13: Installing Martian's GDBM Extention Pack v1.1b

Dec 7 19:06:13: NAME_LOOKUP: Started new lookup process

Dec 7 19:06:13: LOADING: test_core.db

Dec 7 19:06:13: LOADING: Reading values pending finalization ...

Dec 7 19:06:13: LOADING: Reading forked and suspended tasks ...

Dec 7 19:06:13: LOADING: Reading list of formerly active connections ...

Dec 7 19:06:13: LOADING: Reading 221927 objects ...

Dec 7 19:06:13: LOADING: Done reading 10000 objects ...

Dec 7 19:06:13: LOADING: Done reading 20000 objects ...

Dec 7 19:06:14: LOADING: Done reading 30000 objects ...

Dec 7 19:06:14: LOADING: Done reading 40000 objects ...

Dec 7 19:06:14: LOADING: Done reading 50000 objects ...

Dec 7 19:06:15: LOADING: Done reading 60000 objects ...

Dec 7 19:06:15: LOADING: Done reading 70000 objects ...

Dec 7 19:06:15: LOADING: Done reading 80000 objects ...

Dec 7 19:06:16: LOADING: Done reading 90000 objects ...

Dec 7 19:06:16: LOADING: Done reading 100000 objects ...

Dec 7 19:06:16: LOADING: Done reading 110000 objects ...

Dec 7 19:06:17: LOADING: Done reading 120000 objects ...

Dec 7 19:06:17: LOADING: Done reading 130000 objects ...

Dec 7 19:06:17: LOADING: Done reading 140000 objects ...

Dec 7 19:06:18: LOADING: Done reading 150000 objects ...

Dec 7 19:06:18: LOADING: Done reading 160000 objects ...

Dec 7 19:06:18: LOADING: Done reading 170000 objects ...

Dec 7 19:06:19: LOADING: Done reading 180000 objects ...

Dec 7 19:06:19: LOADING: Done reading 190000 objects ...

Dec 7 19:06:19: LOADING: Done reading 200000 objects ...

Dec 7 19:06:19: LOADING: Done reading 210000 objects ...

Dec 7 19:06:20: LOADING: Done reading 220000 objects ...

Dec 7 19:06:20: LOADING: Done reading 221927 objects ...

Dec 7 19:06:20: VALIDATING the object hierarchies ...

Dec 7 19:06:20: VALIDATE: Phase 1: Check for invalid objects ...

Dec 7 19:06:20: VALIDATE: Done through #10000 ...

Dec 7 19:06:20: VALIDATE: Done through #20000 ...

Dec 7 19:06:20: VALIDATE: Done through #30000 ...

Dec 7 19:06:20: VALIDATE: Done through #40000 ...

Dec 7 19:06:20: VALIDATE: Done through #50000 ...

Dec 7 19:06:20: VALIDATE: Done through #60000 ...

Dec 7 19:06:20: VALIDATE: Done through #70000 ...

Dec 7 19:06:20: VALIDATE: Done through #80000 ...

Dec 7 19:06:20: VALIDATE: Done through #90000 ...

Dec 7 19:06:20: VALIDATE: Done through #100000 ...

Dec 7 19:06:20: VALIDATE: Done through #110000 ...

Dec 7 19:06:20: VALIDATE: Done through #120000 ...

Dec 7 19:06:20: VALIDATE: Done through #130000 ...

Dec 7 19:06:20: VALIDATE: Done through #140000 ...

Dec 7 19:06:20: VALIDATE: Done through #150000 ...

Dec 7 19:06:20: VALIDATE: Done through #160000 ...

Dec 7 19:06:20: VALIDATE: Done through #170000 ...

Dec 7 19:06:20: VALIDATE: Done through #180000 ...

Dec 7 19:06:20: VALIDATE: Done through #190000 ...

Dec 7 19:06:20: VALIDATE: Done through #200000 ...

Dec 7 19:06:20: VALIDATE: Done through #210000 ...

Dec 7 19:06:20: VALIDATE: Done through #220000 ...

Dec 7 19:06:20: VALIDATE: Phase 2: Check for cycles ...

Dec 7 19:06:20: VALIDATE: Done through #10000 ...

Dec 7 19:06:20: VALIDATE: Done through #20000 ...

Dec 7 19:06:20: VALIDATE: Done through #30000 ...

Dec 7 19:06:20: VALIDATE: Done through #40000 ...

Dec 7 19:06:20: VALIDATE: Done through #50000 ...

Dec 7 19:06:20: VALIDATE: Done through #60000 ...

Dec 7 19:06:20: VALIDATE: Done through #70000 ...

Dec 7 19:06:20: VALIDATE: Done through #80000 ...

Dec 7 19:06:20: VALIDATE: Done through #90000 ...

Dec 7 19:06:20: VALIDATE: Done through #100000 ...

Dec 7 19:06:20: VALIDATE: Done through #110000 ...

Dec 7 19:06:20: VALIDATE: Done through #120000 ...

Dec 7 19:06:20: VALIDATE: Done through #130000 ...

Dec 7 19:06:20: VALIDATE: Done through #140000 ...

Dec 7 19:06:20: VALIDATE: Done through #150000 ...

Dec 7 19:06:20: VALIDATE: Done through #160000 ...

Dec 7 19:06:20: VALIDATE: Done through #170000 ...

Dec 7 19:06:20: VALIDATE: Done through #180000 ...

Dec 7 19:06:20: VALIDATE: Done through #190000 ...

Dec 7 19:06:20: VALIDATE: Done through #200000 ...

Dec 7 19:06:20: VALIDATE: Done through #210000 ...

Dec 7 19:06:20: VALIDATE: Done through #220000 ...

Dec 7 19:06:20: VALIDATE: Phase 3: Check for inconsistencies ...

Dec 7 19:06:20: VALIDATE: Done through #10000 ...

Dec 7 19:06:20: VALIDATE: Done through #20000 ...

Dec 7 19:06:21: VALIDATE: Done through #30000 ...

Dec 7 19:06:21: VALIDATE: Done through #40000 ...

Dec 7 19:06:21: VALIDATE: Done through #50000 ...

Dec 7 19:06:21: VALIDATE: Done through #60000 ...

Dec 7 19:06:21: VALIDATE: Done through #70000 ...

Dec 7 19:06:21: VALIDATE: Done through #80000 ...

Dec 7 19:06:21: VALIDATE: Done through #90000 ...

Dec 7 19:06:21: VALIDATE: Done through #100000 ...

Dec 7 19:06:22: VALIDATE: Done through #110000 ...

Dec 7 19:06:22: VALIDATE: Done through #120000 ...

Dec 7 19:06:22: VALIDATE: Done through #130000 ...

Dec 7 19:06:22: VALIDATE: Done through #140000 ...

Dec 7 19:06:22: VALIDATE: Done through #150000 ...

Dec 7 19:06:22: VALIDATE: Done through #160000 ...

Dec 7 19:06:23: VALIDATE: Done through #170000 ...

Dec 7 19:06:23: VALIDATE: Done through #180000 ...

Dec 7 19:06:24: VALIDATE: Done through #190000 ...

Dec 7 19:06:24: VALIDATE: Done through #200000 ...

Dec 7 19:06:25: VALIDATE: Done through #210000 ...

Dec 7 19:06:25: VALIDATE: Done through #220000 ...

Dec 7 19:06:26: VALIDATING the object hierarchies ... finished.

Dec 7 19:06:26: LOADING: Reading 9723 MOO verb programs ...

Dec 7 19:06:26: LOADING: Done reading 5000 verb programs ...

Dec 7 19:06:26: LOADING: Done reading 9723 verb programs ...

Dec 7 19:06:26: LOADING: test_core.db done, will dump new database on test_core.db.new

Dec 7 19:06:26: INTERN: 7119013 allocations saved, 141436461 bytes

Dec 7 19:06:26: INTERN: at end, 500733 entries in a 640448 bucket hash table.

Dec 7 19:06:26: Loaded protect cache for 199 builtin functions

Dec 7 19:06:26: RANDOM: seeding from /dev/random

Dec 7 19:06:26: LISTEN: #0 now listening on port 8000

Dec 7 19:06:26: *** Binding listening socket: Address already in use

Dec 7 19:07:21: ### SHUTDOWN: shutdown signal received

Dec 7 19:07:21: DUMPING on test_core.db.new.#1# ...

Dec 7 19:07:21: DUMPING: Writing values pending finalization ...

Dec 7 19:07:21: DUMPING: Writing forked and suspended tasks ...

Dec 7 19:07:21: DUMPING: Writing list of formerly active connections ...

Dec 7 19:07:21: DUMPING: Writing 221927 objects ...

Dec 7 19:07:22: DUMPING: Done writing 221927 objects ...

Dec 7 19:07:23: DUMPING: Done writing 221927 objects ...

Dec 7 19:07:24: DUMPING: Done writing 221927 objects ...

Dec 7 19:07:25: DUMPING: Done writing 221927 objects ...

Dec 7 19:07:26: DUMPING: Done writing 221927 objects ...

Dec 7 19:07:27: DUMPING: Done writing 221927 objects ...

Dec 7 19:07:28: DUMPING: Done writing 221927 objects ...

Dec 7 19:07:29: DUMPING: Done writing 221927 objects ...

Dec 7 19:07:30: DUMPING: Done writing 221927 objects ...

Dec 7 19:07:30: DUMPING: Writing 9723 MOO verb programs ...

Dec 7 19:07:30: DUMPING: Done writing 5000 verb programs ...

Dec 7 19:07:30: DUMPING: Done writing 9723 verb programs ...

Dec 7 19:07:32: DUMPING on test_core.db.new.#1# finished

Littlefield, Tyler

unread,

Dec 7, 2018, 9:15:19 PM12/7/18

to Nathan Smith, MOO Talk

Regular moo would do this too. You're trying to open a port that's already open...

--
You received this message because you are subscribed to the Google Groups "MOO Talk" group.
To unsubscribe from this group and stop receiving emails from it, send an email to MOO-talk+u...@googlegroups.com.
To post to this group, send email to MOO-...@googlegroups.com.
Visit this group at https://groups.google.com/group/MOO-talk.
For more options, visit https://groups.google.com/d/optout.

--

Take Care,
Tyler Littlefield Tyler Littlefield Consulting: website development and business solutions. My personal site My Linkedin @Sorressean on Twitter

Tristan Bussiere

unread,

Dec 7, 2018, 9:41:03 PM12/7/18

to MOO Talk

Please specify what part of the log is problematic. This log looks
entirely fine to me, other than Stunt repeatedly reporting "Done
writing <XXXX> objects..." and using the max obj count instead of the
object it was on in the for loop.

Nathan Smith

unread,

Dec 10, 2018, 8:00:32 PM12/10/18

to MOO Talk

Hi there,

Thanks for your responses,
You were quite right, had a look in db_file.cc, and it was using last_oid, but last_oid never actually changed. changed that to just oid, and it logs like a dream.

I still have a crashing error, but I want to look into that more before I ask for help.

As a prewarning, it is that for some reason, stunt with mysql likes to crash after a few checkpoints?

I am unsure if it checkpoints, or something in a verb as of yet, but it according to the logs, it always crashes after a checkpoint.

Interestingly, not every checkpoint.

Anyways!

thanks all

Nate

Todd Sundsted

unread,

Dec 10, 2018, 9:03:17 PM12/10/18

to MOO Talk

Crashing in checkpoints is not super-surprising because the process of checkpointing goes through every data structure in the server and writes it to disk -- if there is memory corruption anywhere that process will find it. The challenging thing about memory corruption in C/C++ is that the point at which the corruption is introduced (because you're writing past the end of an array or something) is usually not the point at which the corruption causes the crash. Troubleshooting is usually helped by tools like valgrind, which are capable of catching the memory corruption at the point it is introduced rather than the point the app crashes.

Todd

Todd Sundsted

unread,

Dec 10, 2018, 9:03:45 PM12/10/18

to MOO Talk

TL;DR if you want to do moo server hacking you really really need to use something like valgrind :-)

Nathan Smith

unread,

Dec 10, 2018, 9:38:10 PM12/10/18

to MOO Talk

Hi Tod,

I will bare that in mind, and start doing some serious valgrind work.

Thanks as always.

Reply all

Reply to author

Forward