[asterisk-users] Anyone ever experienced a crash where Asterisk debug output a line with all nulls

[Michael Maier]

On 14.08.19 at 16:26 Dan Cropp wrote:
> We have a customer where their VM running Asterisk appears to have crashed.  Fortunately, we had some debugging enabled.
> The asterisk messages file has this... (in notepad+ the blank line in the middle is all [NUL][NUL] [NUL][NUL]....)
> 
> [08/12 15:30:55.880] VERBOSE[6920] app_mixmonitor.c: Begin MixMonitor Recording CBRec/IS__a37ae004-c780-4c7f-88a9-a04402f0ab4e-0000e70f
> [08/12 15:30:55.881] VERBOSE[6921] bridge_channel.c: Channel CBRec/IS__a37ae004-c780-4c7f-88a9-a04402f0ab4e-0000e70f joined 'softmix' base-bridge <23340bca-6823-4c70-a395-e3b092aeb671>
>                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           
> [08/12 15:33:02.887] Asterisk 16.2.1 built by root @ sw-genesis-build4 on a x86_64 running Linux on 2019-04-04 13:41:15 UTC

Did I get it correctly: the last line in the log before asterisk starts again after the reboot is the [nul]-line? If so, are you probably using ext4 or maybe reiserfs? I know of this problem if the machine crashes, open files can end up
like described. AFAIK it's a file system bug!

> We also had debugging enabled and things were output to our debug file for 17 more seconds....
> The blank line in my e-mail is once again a line with all [NUL}... (in notepad+ the blank line in the middle is all [NUL][NUL] [NUL][NUL]....)
> 
> [08/12 15:31:12.776] DEBUG[6781] audiohook.c: Read factory 0x7f079389bff8 and write factory 0x7f079389ca38 both fail to provide 160 samples
> [08/12 15:31:12.777] DEBUG[6709] audiohook.c: Failed to get 160 samples from read factory 0x7f07937066d8
> [08/12 15:31:12.777] DEBUG[6709] audiohook.c: Read factory 0x7f07937066d8 and write factory 0x7f0793707118 both fail to provide 160 samples
>                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                          [08/12 15:33:02.915] Asterisk 16.2.1 built by root @ sw-genesis-build4 on a x86_64 running Linux on 2019-04-04 13:41:15 UTC
> [Aug 12 15:33:02] DEBUG[1385] config.c: Parsing /etc/iss/asterisk/logger.conf
> 
> 
> 
> I believe this was bad enough that Ubuntu actually crashed, but there is nothing in the syslog indicating anything until 15:32:42 where it appears Linux is starting up.
> 
> 
> After this situation happens, every time Asterisk starts up, it was taking significantly longer to load.  Normally 1-2 seconds, became 26-28 seconds.
> [08/12 15:33:03.240] NOTICE[1385] loader.c: 286 modules will be loaded.
> [08/12 15:33:23.844] VERBOSE[1385] loader.c: Loading extconfig.
> 
> 
> Loading the modules is taking 20 seconds after this incident occurred.  Looking at the debug logs, I see the modules loading loader.c PASS.  There all seem to load fine, just much slower than it was previously.

Maybe because the machine is performing a file system check on some other partitions in parallel and it's slowed down therefore?


Regards
Michael