Directory looping out of control

General Help
1

I set up a freepbx box to replace an antiquated phone system where I work and everything works well. The one issue I have is every couple of weeks the asterisk ‘full’ log file grows out of control and eats all available space on the disk. The only way to stop this is to kill the asterisk process, delete the full log file and restart freepbx.

I tried putting

noload => app_directory.so

in my /etc/asterisk/modules.conf because I saw that worked for someone in a similar situation on this forum but that did not stop the issue.

The log looks like:

[Jun 10 12:41:09] DEBUG[2032] app_macro.c: Executed application: GotoIf
[Jun 10 12:41:09] DEBUG[2032] func_db.c: DB: AMPUSER/355/vmx/busy/state not found in database.
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Executing [vmx@macro-vm:5] NoOp(“Zap/2-1”, "Checking if ext 355 is enabled: ") in new stack
[Jun 10 12:41:09] DEBUG[2032] app_macro.c: Executed application: Noop
[Jun 10 12:41:09] DEBUG[2032] func_db.c: DB: AMPUSER/355/vmx/busy/state not found in database.
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Executing [vmx@macro-vm:6] GotoIf(“Zap/2-1”, “1?s-BUSY|1”) in new stack
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Goto (macro-vm,s-BUSY,1)
[Jun 10 12:41:09] DEBUG[2032] app_macro.c: Executed application: GotoIf
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Executing [s-BUSY@macro-vm:1] NoOp(“Zap/2-1”, “BUSY voicemail”) in new stack
[Jun 10 12:41:09] DEBUG[2032] app_macro.c: Executed application: NoOp
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Executing [s-BUSY@macro-vm:2] Macro(“Zap/2-1”, “get-vmcontext|355”) in new stack
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Executing [s@macro-get-vmcontext:1] Set(“Zap/2-1”, “VMCONTEXT=default”) in new stack
[Jun 10 12:41:09] DEBUG[2032] app_macro.c: Executed application: Set
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“Zap/2-1”, “0?200:300”) in new stack
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Goto (macro-get-vmcontext,s,300)
[Jun 10 12:41:09] DEBUG[2032] app_macro.c: Executed application: GotoIf
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Executing [s@macro-get-vmcontext:300] NoOp(“Zap/2-1”, “”) in new stack
[Jun 10 12:41:09] DEBUG[2032] app_macro.c: Executed application: NoOp
[Jun 10 12:41:09] DEBUG[2032] app_macro.c: Executed application: Macro
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – Executing [s-BUSY@macro-vm:3] VoiceMail(“Zap/2-1”, “355@default|sb”) in new stack
[Jun 10 12:41:09] VERBOSE[2032] logger.c: – <Zap/2-1> Playing ‘/var/spool/asterisk/voicemail/default/355/busy’ (language ‘en’)
[Jun 10 12:41:12] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:14] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2026] logger.c: == Spawn extension (macro-vm, o, 15) exited non-zero on ‘Zap/1-1’ in macro ‘vm’
[Jun 10 12:41:19] VERBOSE[2026] logger.c: == Spawn extension (macro-vm, o, 15) exited non-zero on ‘Zap/1-1’ in macro ‘exten-vm’
[Jun 10 12:41:19] VERBOSE[2026] logger.c: == Spawn extension (macro-vm, o, 15) exited non-zero on ‘Zap/1-1’
[Jun 10 12:41:19] VERBOSE[2026] logger.c: – Hungup ‘Zap/1-1’
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] WARNING[2031] file.c: Failed to write frame
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – <Local/s@from-pstn-14b0,2> Playing ‘dir-intro’ (language ‘en’)
[Jun 10 12:41:19] VERBOSE[2031] logger.c: – Playing ‘dir-nomatch’ (escape_digits=) (sample_offset 0)

Any ideas?

Thanks
Nathan

2

You would be better off editing the file in /etc/logrotate.d/asterisk and including the /etc/log/asterisk/full in the log rotation schedule that once a week (or day) so that the file can’t grow out of control. Then you can even think about compressing the logs that are kept.

3

That might solve the issue with the log file taking up the entire disk space but the real issue is the continuous loop that asterisk falls into that writes hundreds of lines to the log file per second.

4

Agreed.

But there is not enough information to help. what version of asterisk, FreePBX, this a hand built box? if so what OS and set of directions did you use, if it is a distro which and what version? is it up to date?

dir-nomatch and dir-intro are used by the directory agi script (might be ued in other locations also) but I don’t see how it entered into that script from your provided output as the call was going into voicemail for extension 355 and getting the I’m busy audio recording.

so increase the verbose level to say 5 (asterisk -rvvvvv) and re-capture it and post it. because there is not enough information to guess at there.

There are MANY reasons for “Failed to write frame”

5

Sorry for the slow reply, I took a bit of a vacation and haven’t had a chance to get back here. Below is the additional info you requested on my system.

I am running this on a Debian 4.0 box with the following software downloaded from source and compiled:
linux kernel 2.6.23.9
asterisk 1.4.17
freepbx 2.3.1
zaptel 1.4.8

This problem is tricky to catch because it only happens every couple months. I can’t figure out the conditions that trigger the problem so I can’t readily reproduce it and get the output. All I have been able to do is write a cron job that checks for the issue and then notifies me if it occurs. Then I have to scan through the /var/log/asterisk/full log to try and find a clue as to what caused this.

Nathan