Common troubleshooting methods for issues that Logs cannot be displayed on GUI

This section summarizes the common troubleshooting methods for log related issues such as Attack/Traffic/Event logs not generated or displayed on GUI. The following sections will use these methods to actually locate specific issues step by step.

1. Check if the security level in log disk is configured properly on CLI or GUI.

Take below configuration for example, only the log messages with a severity of Warning or higher will be recorded.

FortiWeb # show full-configuration log disk

config log disk

set status enable

set severity warning

set diskfull overwrite

end

Please note: Log level of traffic log is Notification and log level of attack log is Alert.

2. Double check if log options are enabled correctly:

• Make sure global log options are enabled via GUI or CLI as below:

  FortiWeb # show full log event-log

  config log event-log

  set status enable

  end

  FortiWeb # show full log traffic-log

  config log traffic-log

  set status enable

  end

  FortiWeb # show full log attack-log

  config log attack-log

  set status enable

  end

• On 6.4.16, 7.0.0 and later releases, traffic log is disabled by default and can be enabled or disabled per server-policy policy via CLI:

  FortiWeb # show full-configuration server-policy policy

  config server-policy policy

  edit "SP_01"

  set tlog enable

  next

3. Check if logd, indexd and mysqld work normally in backend:

Sometimes logs fail to be displayed are caused by log related daemons instability such as coredump.

There are several ways to judge if these three daemons every restarted abnormally:

• Check the PID number of related daemons. The PID of logd and mysqld are usually a small 4-digit one like below, so if the PID becomes a big number, it may indicate the daemon ever restarted.
• Check the PID of the 3 daemons several times to make sure they are stable (PID is not changing). If the PID of the daemons is changing, it indicates the daemon ever restarted or the administrator ever executed “execute db rebuild”.

  # ps | grep logd

  1479 root 4508 S /bin/syslogd -n -b 99 -s 500

  1480 root 4508 S /bin/klogd -n

  1502 root 308m S /bin/logd #1502 is the PID of logd

  1729 shell 4508 R grep logd

  # ps | grep indexd

  2133 shell 4508 S grep indexd

  18411 root 55840 S /bin/indexd #18411 is PID of indexd

  # ps | grep mysqld

  1584 root 773m S /bin/mysqld --defaults-file=/data/etc/mysql/my-fortiweb.cnf --skip-grant-tables --user=root #1584 is PID of mysqld

  2139 root 0 Z [mysqld_monitor.]

  2328 shell 4508 S grep mysqld

• Another way is to check .NMON files. The PID of daemons are recorded in each .NMON file > TOP.

  Please refer to Retrieving system logs in backend system to see how to analyze .NMON files.

  

• If you find logd daemon of kernel coredump files, please download them and deliver to R&D for further investigationAnother way is to check.

  Please note: logd coredump need to be enabled with the following command in backend shell: (please refer to "Run backend shell commands' in this guide)

  /# touch /var/log/debug/logrpt_core_flag

  Please refer to "Customize & Download debug logs” in this guide to see how to download coredump files.

4. Use diagnose commands to check logds outputs:

“diagnose debug application logd” is very useful to help find the cause for log related issues.

Hereby we’ll provide several specific case/examples:

• When no useful log is printed out when diagnose is enabled, it usually means no logs are sent to logd by other function modules.

  FortiWeb # diagnose debug application logd 7

  FortiWeb # diagnose debug timestamp enable

  FortiWeb # diagnose debug enable

  ##When either the global traffic-log or per server-policy traffic log option is disabled, there will be no useful diagnose information:

  VM_01 # [Logd][11-22-16:29:12][INFO][_log_try_push][436]: log try push 10 times

  ##If traffic log is enabled, there will be diagnose info like below:

  VM_01 # [Logd][11-22-16:39:27][INFO][_log_process][383]: ###### Recv a traffic log

  [Logd][11-22-16:39:27][INFO][log_format_local_msg][512]: log_id=30001000, msg_id=000000001063, subtype=HTTPs, url=/

  [Logd][11-22-16:39:27][INFO][log_format_local_msg][578]: Local Detail = v011xxxxdate=2021-11-22 time=16:39:27 log_id=30001000 msg_id=000000001063 device_id=FVVM04TM21000715 vd="root" timezone="(GMT-7:00)Mountain Time(US&Canada)" timezone_dayst="GMTb+7" type=traffic subtype="HTTPs" pri=notice proto=tcp service=HTTPs/tls1.2 status=success reason=none policy="SP_02_RS_SSL" original_src=172.30.213.248 src=172.30.213.248 src_port=3067 dst=10.159.37.11 dst_port=443 HTTP_request_time=0 HTTP_response_time=0 HTTP_request_bytes=82 HTTP_response_bytes=927 HTTP_method=get HTTP_url="/" HTTP_agent="curl/7.78.0" HTTP_retcode=200 msg="HTTPS get request from 172.30.213.248:3067 to 10.159.37.11:443" original_srccountry="Reserved" srccountry="Reserved" content_switch_name="none" server_pool_name="Pool_HTTPS" HTTP_host="test.vm02.com:8002" user_name="Unknown" HTTP_refer="none" HTTP_version="1.x" dev_id=B039BB143F81FCEBE2C39ACC361EE9411534 cipher_suite="TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384"

  [Logd][11-22-16:39:27][WARNING!][log_format_msg][1718]: No srv need to send

  [Logd][11-22-16:39:27][INFO][_log_process][403]: Begin to write disk.

  [Logd][11-22-16:39:27][INFO][_log_process][409]: Begin to write packet.

  [Logd][11-22-16:39:27][INFO][_log_add_pkt][545]: packet log cache 1 logs stored

  [Logd][11-22-16:39:27][INFO][_log_process][412]: Process done.

  [Logd][11-22-16:39:27][INFO][log_disk_push][988]: push tlog 915

  [Logd][11-22-16:39:27][INFO][_log_write_disk][622]: Open existing log file '/var/log/fwlog/root/disklog/tlog(2021-11-22-16:39:27).log' with link

  [Logd][11-22-16:39:27][INFO][write_cache_to_file][277]: cur cnt: 3 start pos = 1744,len = 915,currnet len = 2659

  [Logd][11-22-16:39:27][INFO][write_cache_to_file][337]: Write log item Traffic log 1 msg_id 000000001063 start offset : 2659 length : 915

  [Logd][11-22-16:39:27][INFO][write_cache_to_file][347]: cur_log_cnt : 4,cache type = Traffic log cache count : 1

• Sometimes one may be not sure about the severity of specific attack/traffic logs, you can use the diagnose commands to debug:

  FortiWeb # diagnose debug application logd 7

  FortiWeb # diagnose debug timestamp enable

  FortiWeb # diagnose debug enable

  Sample diagnose output:

  [Logd][10-18-12:47:02][WARNING!][log_disk_write][921]: Disk log rejected! t:2, s:1, 4 < 5? h->category : 2

  [Cause] The traffic log level is notification but disk log severity is set as Warning, so logs are not recorded to local disk.

  [Explanation] Both t:2 & h->category : 2 mean traffic log; s:1 means log is enabled to write to disk; 4 < 5 means current severity level is 5 (Notification), while the current log severity is 4 (Warning).

5. Check backend logs:

Usually diagnose output will show most useful debug information, while sometimes we need to double check or find the root cause via more detailed backend logs or counters.

• /var/log/dlog_indexd

  We can use realtime output with “tail -f” or “grep” with keywords such as “can't connect”, “error” or “mysqld segment fault” to check if there are any obvious defaults in dlog_indexd.

  Example 1:

  “MySQL server has gone away” means mysql server used by logd cannot be connected, so logs cannot be recorded successfully.

  /# tail -f /var/log/dlog_indexd

  /var/log/fwlog/root/disklog/alog(2021-11-15-14:01:53).log has no mapping entry

  11-16-16:48:28.157212! 2818: dlog_indexer.c(3569)@__mapping_get_tname:

  mysqlerr 2 0: MySQL server has gone away

  11-16-16:48:28.157218! 2818: dlog_indexer.c(3508)@__mapping_get_maxid:

  mysqlerr 1 8: MySQL server has gone away

  11-16-16:48:28.157228! 2818: dlog_indexer.c(2210)@_create_log_tab

  Example 2:

  /# cat /var/log/dlog_indexd | grep mysql

  cannot connect mysql, try walk around (ret:0), mysqlerr 1:Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2)

  cannot connect mysql, try walk around (ret:0), mysqlerr 1:Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2)

  cannot connect mysql, try walk around (ret:0), mysqlerr 1:Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2)

• /var/log/mysql/error.log

  Similarly, we can also check if there is any fault in this log file:

  /# cat /var/log/dlog_indexd | grep mysql

  cannot connect mysql, try walk around (ret:0), mysqlerr 1:Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2)

  cannot connect mysql, try walk around (ret:0), mysqlerr 1:Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2)

  cannot connect mysql, try walk around (ret:0), mysqlerr 1:Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2)

• /var/log/fwlog/root/disklog

  All attack/event/traffic logs will be written to harddisk after logd received and handled logs sent by other modules. Outputs in this file will help to check if logs have been written to the local disk successfully.

  /var/log/fwlog/root/disklog# ls -l

  -rw-r--r-- 1 root 0 417601 Nov 22 22:27 alog(2021-11-22-22:26:09).log

  lrwxrwxrwx 1 root 0 57 Nov 22 22:26 alog.log -> /var/log/fwlog/root/disklog/alog(2021-11-22-22:26:09).log

  -rw-r--r-- 1 root 0 459145 Nov 23 10:27 elog(2021-11-22-14:34:23).log

  lrwxrwxrwx 1 root 0 57 Nov 22 14:34 elog.log -> /var/log/fwlog/root/disklog/elog(2021-11-22-14:34:23).log

  -rw-r--r-- 1 root 0 46946294 Nov 22 23:13 tlog(2021-11-22-15:59:23).log

  -rw-r--r-- 1 root 0 45953552 Nov 22 23:55 tlog(2021-11-22-23:13:38).log

  lrwxrwxrwx 1 root 0 57 Nov 22 23:13 tlog.log -> /var/log/fwlog/root/disklog/tlog(2021-11-22-23:13:38).log

  #One can just check the soft link for the latest logs.

  /var/log/fwlog/root/disklog# tail -f tlog.log

  v011xxxxdate=2021-11-23 time=10:37:11 log_id=30001000 msg_id=000000102564 device_id=FVVM04TM21000715 vd="root" timezone="(GMT-7:00)Mountain Time(US&Canada)" timezone_dayst="GMTb+7" type=traffic subtype="HTTPs" pri=notice proto=tcp service=HTTPs/tls1.2 status=success reason=none policy="SP_01" original_src=172.30.213.98 src=172.30.213.98 src_port=1941 dst=10.159.26.123 dst_port=80 HTTP_request_time=0 HTTP_response_time=0 HTTP_request_bytes=82 HTTP_response_bytes=923 HTTP_method=get HTTP_url="/" HTTP_agent="curl/7.78.0" HTTP_retcode=200 msg="HTTPS get request from 172.30.213.98:1941 to 10.159.26.123:80" original_srccountry="Reserved" srccountry="Reserved" content_switch_name="none" server_pool_name="Pool_Single" HTTP_host="test.vm01.com:7002" user_name="Unknown" HTTP_refer="none" HTTP_version="1.x" dev_id=03AFBEAE2124AE47968CB4271208410FF9A8 cipher_suite="TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384"

6. Check log related backend counters:

Logd will receive, handle, index and display logs sent by the system processes or specific function modules on GUI, while in abnormal situations it fails to do so. Then it’s useful to double check with two backend counters for attack/event/traffic logs.

/# cd /proc/miglog/

/proc/miglog# ls

alog dlog elog tlog

/proc/miglog# ls alog/

brief queue_max_len

/proc/miglog# ls elog/

brief queue_max_len

/proc/miglog# ls tlog/

brief queue_max_len

/proc/miglog# ls dlog/ #dlog is for debug only; just ignore it

brief queue_max_len

/proc/miglog/tlog# cat queue_max_len

163840 #The log queue length; usually fixed

/proc/miglog/tlog# cat brief

total 4

enqueued 4 #New logs are sent from other process/module; one new HTTP/HTTPS session usually increase this count by 1

dequeued 4 #New logs received are processed by logd; should be the same as enq

overflow 0 #Not 0 means log overflows caused by too many logs generated; one may need check current CPS or disable traffic logs

error 0 #kernel errors that cause logging failures

7. Use “execute db rebuild” to rebuild log database :

Use this command to rebuild the FortiWeb appliance’s internal database that it uses to store log messages. Please note there are some behavior differences between 6.x and later releases:

• On 6.x builds, db rebuild also erases databases for ML, while on 7.0.0 and later builds, this operation will only clean and rebuild databases for disklog; you can execute redis rebuild to clean ML databases.

• Historical traffic/attack/eventlogs will not be cleared, while one needs to wait several minutes for log index rebuilding - the time is based on log amount;

• In HA mode, executing db rebuild on primary appliance will take effect on all secondary appliances simultaneously on 6.x builds, whereas on 7.0.0 and later builds, rebuilding just impacts local box instead of the whole HA groups.

• With 6.x builds, executing this command will trigger FortiWeb system reboot, while with 7.0.0 and later, this command will not lead to system reboot.

  6.x old builds: (Reboot system)

  FortiWeb# exec db rebuild

  This operation will clean and rebuild database for disklog, and will clean database for ML and Client Management, and it will reboot the system!

  Do you want to continue? (y/n)y

  rebuilding the database......

  FortiWeb# Connection closing...Socket close.

  FortiWeb starts to reboot...

  6.3.16, 7.0.0 and later: (Not reboot system)

  FortiWeb # execute db rebuild

  This operation will clean and rebuild database for disklog.

  Do you want to continue? (y/n)y

  rebuilding the database......

  FortiWeb #

For some cases, it would take a long time to complete database rebuild (depending on how many logs there are existing). While the database is rebuilding, new generated logs are postponed to be written to the database so that the newly generated logs are not available immediately on GUI. The logs are all saved in log files. No log would be lost.

8. Use “execute formatlogdisk” to clear the logs from the FortiWeb appliance’s hard disk and reformat the disk.

This operation is more dangerous than “execute db rebuild” because it formats the whole log disk /var/log, so all logs and databases used by varied modules stored on this disk will be cleared.

One point here is, signatures will be cleared so they will be downloaded again after system reboot. (proxyd restart will re-create the signature database)

FortiWeb # execute formatlogdisk

This operation will clear all logs on the Hard Disk and take a few minutes depending on the disk size!!

Please backup system configuration and restore it after format operation, otherwise openapi data will be lost!

Do you want to continue? (y/n)y

/# df -h

Filesystem Size Used Available Use% Mounted on

/dev/root 472.5M 355.6M 117.0M 75% /

none 1.1G 176.0K 1.1G 0% /tmp

none 3.8G 2.9M 3.8G 0% /dev/shm

/dev/sda2 362.4M 270.0M 72.8M 79% /data

/dev/sda3 90.6M 56.0K 85.6M 0% /home

/dev/sda4 30.5G 604.4M 28.4G 2% /var/log