commit hangs on 98%

[jsk]

Hi,

I had an antivirus download/install job that had "download in progress" for several days. I restarted device server and management server,

after this the antivirus downloaded and installed.

Now when I try to commit policy changes, status says 98% for several hours (+5).

Any way I can troubleshoot this?

CLI commands used:

> debug software restart device-server

> debug software restart management-server)

PA500 - v4.1.10

Thanks,

Jakob

[hshah]

Hi Jakob,

Following command would temporary fix the issue.

> debug software restart device-server

> debug software restart management-server

For troubleshooting you should do following things.

1. Open 3 CLI sessions.

2. 1 CLI session run "tail follow yes mp.log ms,log"

3. 2 CLI session run "tail follow yes mp.log devsrv.log"

4. 3 CLI session "commit" changes.

Now check error log in step 2 and 3 when commit stops.

Regards,

Hardik Shah

[HULK]

Hello Jakob,

Could you please also share below mentioned CLI command output:

> show management-clients

> show jobs all   >>>> identify the Job ID

>show job id XYZ

Thanks

[jsk]

Hi Hulk,

show management-clients

              Client PRI    State Progress

-------------------------------------------------------------------------

              routed  30    P1-ok       99

            ha_agent  25    P1-ok       99

              device  20    P1-ok       99

              ikemgr  10    P1-ok       99

              keymgr  10     init        0    (op cmds only)

             logrcvr  10    P1-ok       99

               dhcpd  10    P1-ok       99

             varrcvr  10    P1-ok       99

               l3svc  10    P1-ok       99

              sslvpn  10  P1-sent      100

              rasmgr  10    P1-ok       99

             useridd  10    P1-ok       99

             websrvr  10    P1-ok       99

              sslmgr  10    P1-ok       99

               authd  10    P1-ok       99

              pppoed  10    P1-ok       99

           dnsproxyd  10    P1-ok       99

             cryptod  10    P1-ok       99

              dagger  10     init        0    (op cmds only)

Overall status: P1-sent. Progress: 0

Warnings:

Errors:

device: VSYS1

device:     vsys1: Rule 'rule_outlook_lab' application dependency warning:

device:         Application 'ms-exchange' requires 'msrpc' be allowed, but 'msrp

c' is denied in Rule 'rule24'

device:     vsys1: Rule 'rule_outlook_kw' application dependency warning:

device:         Application 'ms-exchange' requires 'msrpc' be allowed, but 'msrp

c' is denied in Rule 'rule22'

device:     vsys1: Rule 'rule21' application dependency warning:

device:         Application 'citrix' requires 'socks' be allowed, but 'socks' is

denied in Rule 'rule22'

device:     vsys1: Rule 'rule23' application dependency warning:

device:         Application 'citrix' requires 'socks' be allowed, but 'socks' is

denied in Rule 'rule24'

device:     vsys1: Rule 'rule25' application dependency warning:

device:         Application 'citrix' requires 'socks' be allowed, but 'socks' is

denied in Rule 'rule26'

device:     Security Policy:

device:     - Rule 'rule31' shadows rule 'rule32'

device:     - Rule 'rule33' shadows rule 'rule34'

device:     - Rule 'rule36' shadows rule 'rule37'

device: (Module: device)

show jobs all

Enqueued                     ID             Type    Status Result Completed

--------------------------------------------------------------------------

2014/09/17 12:49:10 

show jobs id 1

Enqueued                     ID             Type    Status Result Completed

--------------------------------------------------------------------------

2014/09/17 12:49:10           1           Commit       ACT   PEND        98%

Warnings:

Details:VSYS1

    vsys1: Rule 'rule_outlook_lab' application dependency warning:

        Application 'ms-exchange' requires 'msrpc' be allowed, but 'msrpc' is denied in

Rule 'r

ule24'

    vsys1: Rule 'rule_outlook_kw' application dependency warning:

        Application 'ms-exchange' requires 'msrpc' be allowed, but 'msrpc' is denied in

Rule 'r

ule22'

    vsys1: Rule 'rule21' application dependency warning:

        Application 'citrix' requires 'socks' be allowed, but 'socks' is denied in Rule

'rule22

'

    vsys1: Rule 'rule23' application dependency warning:

        Application 'citrix' requires 'socks' be allowed, but 'socks' is denied in Rule

'rule24

'

    vsys1: Rule 'rule25' application dependency warning:

        Application 'citrix' requires 'socks' be allowed, but 'socks' is denied in Rule

'rule26

'

    Security Policy:

    - Rule 'rule31' shadows rule 'rule32'

    - Rule 'rule33' shadows rule 'rule34'

    - Rule 'rule36' shadows rule 'rule37'

(Module: device)

[jsk]

Hi hshah,

Not sure what to get from this. Phase 1 is successful, still stuck on 98%:

ms-log

(Module: device)

Sep 18 07:28:11 client useridd reported Phase 1 was SUCCESSFUL

Sep 18 07:28:23 client device reported Phase 1 was SUCCESSFUL

...

Sep 18 07:34:01 Getting authorization info for user admin succeeded.

Sep 18 07:34:02 client dagger reported op command was SUCCESSFUL

devsrv-log

Sep 18 07:27:12 Config commit phase1 started

Sep 18 07:27:12 Last committed config available: no

Sep 18 07:27:12 TDB compilation started

Sep 18 07:27:13 Content Engine version: 0x4010000 APP version: 0x1c60933, Threat 0x1c60933

/opt/pancfg/mgmt/content//global/.global_app.xml is newer

/opt/pancfg/mgmt/content//global/.global_threat.xml is newer

Sep 18 07:27:13 End of translating global

Sep 18 07:27:24 End of parsing custom threat

[TDB] Loading tdb cache  with virus loaded

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 10 aho partition 68

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 12 aho partition 69

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 19 aho partition 83

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 27 aho partition 70

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 29 aho partition 78

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 30 aho partition 79

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 42 aho partition 71

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 49 aho partition 72

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 51 aho partition 73

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 54 aho partition 84

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 61 aho partition 64

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 62 aho partition 74

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 64 aho partition 75

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 66 aho partition 80

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 67 aho partition 76

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 70 aho partition 81

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 71 aho partition 82

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 72 aho partition 65

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 73 aho partition 66

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 75 aho partition 77

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 79 aho partition 85

Sep 18 07:27:28 Warning: pan_tdb_unserialize(pan_tdb_ser.c:1077): [regex group above 63 appid 80 aho partition 67

Sep 18 07:27:29 [Cache] Load /opt/pancfg/mgmt/content//cache/40100//tdb.cache.ser-0 success

Sep 18 07:27:29 [TDB] compile virus cache

Sep 18 07:27:36 TDB compilation done

Sep 18 07:27:48 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 10000 AND id < 30000  AND (  severity = 5  )

Sep 18 07:27:48 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 10000 AND id < 30000  AND (  severity = 4  )

Sep 18 07:27:48 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 10000 AND id < 30000  AND (  severity = 3  )

Sep 18 07:27:48 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 10000 AND id < 30000  AND (  severity = 2  )

Sep 18 07:27:48 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 30000 AND id < 45000  AND (  severity = 5  )  AND ( host = 1 OR host = 3)

Sep 18 07:27:49 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 30000 AND id < 45000  AND (  severity = 4  )  AND ( host = 1 OR host = 3)

Sep 18 07:27:50 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 30000 AND id < 45000  AND (  severity = 3  )  AND ( host = 1 OR host = 3)

Sep 18 07:27:51 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 30000 AND id < 45000  AND (  severity = 5  )  AND ( host = 2 OR host = 3)

Sep 18 07:27:51 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 30000 AND id < 45000  AND (  severity = 4  )  AND ( host = 2 OR host = 3)

Sep 18 07:27:51 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 30000 AND id < 45000  AND (  severity = 3  )  AND ( host = 2 OR host = 3)

Sep 18 07:27:51 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 10000 AND id < 30000  AND (  severity = 5  )

Sep 18 07:27:51 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 10000 AND id < 30000  AND (  severity = 4  )

Sep 18 07:27:51 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 10000 AND id < 30000  AND (  severity = 3  )

Sep 18 07:27:51 sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db query SELECT id from tdb WHERE id >= 10000 AND id < 30000  AND (  severity = 2  )

Sep 18 07:27:53 Retrieved stored platform base MAC address 00:1b:17:3e:ed:00

Sep 18 07:27:53 Computed platform base MAC address 00:1b:17:3e:ed:00 from configuration

Sep 18 07:27:58 Error: pan_region_from_region_entries(pan_region.c:180): pan_address_parse_address failed

Sep 18 07:28:00 policy egt stat: memuse 16280, nrules 33, nip_pairs 56, natoms 1692, both_egts no

Sep 18 07:28:00 policy egt stat: memuse 1886, nrules 4, nip_pairs 4, natoms 20, both_egts no

Sep 18 07:28:03 phase1: modifying cfgpush.*.*.*.cfg

Sep 18 07:28:10 push config takes 7 sec

Sep 18 07:28:10 appsig changed

Sep 18 07:28:10 tdb changed

Sep 18 07:28:16 Warning: pan_l3svc_cfg_parse(pan_l3svc.c:509): vsys id is not specified

Sep 18 07:28:16 Warning: pan_l3svc_cfg_parse(pan_l3svc.c:509): vsys id is not specified

Sep 18 07:28:16 Warning: pan_l3svc_cfg_parse(pan_l3svc.c:509): vsys id is not specified

Sep 18 07:28:23 Config commit phase1 done

Sep 18 07:29:50 Retry once for idle connection

Sep 18 07:29:50  ip 54.72.138.125 message RT time 0.066

Sep 18 07:29:50 Best IP for service.brightcloud.com is 54.72.138.125

Sep 18 07:29:50 Connected to Brightcloud update server service.brightcloud.com

Sep 18 07:30:00 Error: pan_prev_stats_readin(pan_status_handler.c:486):

appstat read-back failed for /tmp/ds_appstat.0.prev

Sep 18 07:30:00

appstat readback successfully for vsys=001

[hshah]

Hi Jsk,

Thanks alot for output. Following error means its most likely a bug, hence upgrade or reboot is required.

sqlite3 /opt/pancfg/mgmt/content/global/threats.xml.db

Can you please tell me which PAN-OS is being used?

Also provide me output for "show system files"

Regards,

Hardik Shah

[jsk]

Hardik,

We use PAN_OS 4.1.10.

show system files.

/opt/dpfs/var/cores/:

total 4.0K

drwxrwxrwx 2 root root 4.0K Feb  2  2013 crashinfo

/opt/dpfs/var/cores/crashinfo:

total 0

/var/cores/:

total 73M

-rw-r--r-- 1 root root  17M Nov  1  2013 websrvr_4.1.10_0.tar.gz

drwxrwxrwx 2 root root 4.0K Sep 17 12:40 crashinfo

-rw-r--r-- 1 root root  57M Sep 17 12:50 mgmtsrvr_4.1.10_0.tar.gz

/var/cores/crashinfo:

total 20K

-rw-rw-rw- 1 root root 7.6K Nov  1  2013 websrvr_4.1.10_0.info

-rw-rw-rw- 1 root root 8.4K Sep 17 12:40 mgmtsrvr_4.1.10_0.info

Regards,

Jakob

[hshah · Accepted solution]

Hi JSk,

There are two crash info for management server and web server for yesterday. This clearly prooves its a software issue.

Moreover you are on 4.1.0, hence I would suggest to upgrade.

If you are really interested in crash info analysis than open a TAC case. Because that would not be possible on forum.

Regards,

Hardik Shah

[jsk]

Hi Hardik,

Thanks a lot. I will consider an upgrade, but for now probably just reboot since I cant have to much downtime right now.

Best regards,

Jakob