Bug report: filters gone on upgrade: Cannot invoke "String.length()" because "id" is null

[halfgaar]

(Not sure where to report (open source) bugs these days. The bugzilla seems broken, Github has no issues and the a recent blog post said to send it so the support staff, for the commercial customers)

I've had it twice now, upgrading Zimbra, that one users mail filters disappears, and he got the error 'Cannot invoke "String.length()" because "id" is null' in a pop-up. The pop-up appeared when clicking 'filters' in the preferences menu.

The 'mailbox.log' also showed it:

Code: Select all

2024-09-25 21:16:57,609 WARN  [qtp704024720-148://webmeel.example.net/service/soap/GetFilterRulesRequest] [name=redacted@example.net;mid=11;ip=83.137.146.229;port=46068;ua=ZimbraWebClient - FF130 (Win)/10.1.1_GA_4200000;soapId=7a0d8bb4;] SoapEngine - handler exception                                                                                                                                                                                                                                                                             
java.lang.NullPointerException: Cannot invoke "String.length()" because "id" is null                                                                                                                                                                                           
        at java.util.TimeZone.parseCustomTimeZone(TimeZone.java:801) ~[?:?]                                                                                                                                                                                                    
        at java.util.TimeZone.getTimeZone(TimeZone.java:580) ~[?:?]                                                                                                                                                                                                            
        at java.util.TimeZone.getTimeZone(TimeZone.java:518) ~[?:?]                                                                                                                                                                                                            
        at com.zimbra.common.util.DateParser.getFormatter(DateParser.java:55) ~[zimbracommon.jar:10.1.1_GA_4200000]                                                                                                                                                            
        at com.zimbra.common.util.DateParser.parse(DateParser.java:41) ~[zimbracommon.jar:10.1.1_GA_4200000]                                                                                                                                                                   
        at com.zimbra.cs.filter.SieveVisitor.acceptTest(SieveVisitor.java:627) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                            
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:431) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:435) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:435) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:411) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.acceptTest(SieveVisitor.java:453) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                            
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:431) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:435) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:428) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:435) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:411) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:403) ~[zimbrastore.jar:10.1.1_GA_4200000]
        and a lot more

It happened on upgrading to:

• zcs-10.1.1_GA_4200000.UBUNTU20_64.20240923190825
• zcs-10.1.2_GA_4200000.UBUNTU20_64.20240924075512

These are builds from Maldua.

The user recreated filters the first time it happened, based on restoring a backup snapshot to a copy virtual machine. And so they disappeared again when we upgraded to 10.1.2.

Code: Select all

# cat /etc/lsb-release 
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=20.04
DISTRIB_CODENAME=focal
DISTRIB_DESCRIPTION="Ubuntu 20.04.6 LTS"

root@meel: ~/10
# uname -a
Linux meel 5.4.0-198-generic #218-Ubuntu SMP Fri Sep 27 20:18:53 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

[adrian.gibanel.btactic]

(Not sure where to report (open source) bugs these days. The bugzilla seems broken, Github has no issues and the a recent blog post said to send it so the support staff, for the commercial customers)

These are builds from Maldua.

I also report them here in Developers forum hoping that someone takes a look at them XD.

If you think the bug is specific to Maldua you can also open an issue at https://github.com/maldua/zimbra-foss-builder/issues.

[halfgaar]

If you think the bug is specific to Maldua you can also open an issue at https://github.com/maldua/zimbra-foss-builder/issues.

I don't think so. The particular null reference exception is too specific.

[adrian.gibanel.btactic]

I've had it twice now, upgrading Zimbra, that one users mail filters disappears, and he got the error 'Cannot invoke "String.length()" because "id" is null' in a pop-up. The pop-up appeared when clicking 'filters' in the preferences menu.

The 'mailbox.log' also showed it:

Code: Select all

2024-09-25 21:16:57,609 WARN  [qtp704024720-148://webmeel.example.net/service/soap/GetFilterRulesRequest] [name=redacted@example.net;mid=11;ip=83.137.146.229;port=46068;ua=ZimbraWebClient - FF130 (Win)/10.1.1_GA_4200000;soapId=7a0d8bb4;] SoapEngine - handler exception                                                                                                                                                                                                                                                                             
java.lang.NullPointerException: Cannot invoke "String.length()" because "id" is null                                                                                                                                                                                           
        at java.util.TimeZone.parseCustomTimeZone(TimeZone.java:801) ~[?:?]                                                                                                                                                                                                    
        at java.util.TimeZone.getTimeZone(TimeZone.java:580) ~[?:?]                                                                                                                                                                                                            
        at java.util.TimeZone.getTimeZone(TimeZone.java:518) ~[?:?]                                                                                                                                                                                                            
        at com.zimbra.common.util.DateParser.getFormatter(DateParser.java:55) ~[zimbracommon.jar:10.1.1_GA_4200000]                                                                                                                                                            
        at com.zimbra.common.util.DateParser.parse(DateParser.java:41) ~[zimbracommon.jar:10.1.1_GA_4200000]                                                                                                                                                                   
        at com.zimbra.cs.filter.SieveVisitor.acceptTest(SieveVisitor.java:627) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                            
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:431) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:435) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:435) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:411) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.acceptTest(SieveVisitor.java:453) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                            
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:431) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:435) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:428) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:435) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:411) ~[zimbrastore.jar:10.1.1_GA_4200000]                                                                                                                                                                
        at com.zimbra.cs.filter.SieveVisitor.accept(SieveVisitor.java:403) ~[zimbrastore.jar:10.1.1_GA_4200000]
        and a lot more

It happened on upgrading to:

• zcs-10.1.1_GA_4200000.UBUNTU20_64.20240923190825
• zcs-10.1.2_GA_4200000.UBUNTU20_64.20240924075512

1) I have just noticed that you already reported this problem and you got to the conclusion that it was triggered by the final user having deleted one of the target folders of his filters.

Are you reporting the same bug or another one?

Maybe the bug might be about the sieve/filters parser not being resilient enough when it has inconsistent/faulty data?

2) In any case you should be able to dump the (input) filters thanks to:

Code: Select all

zmprov getAccount user@example.net zimbraMailSieveScript > dump_sieve.txt

.
I mean... thanks to a VM snapshot you can dump those filters into a file, trigger the lost of them and then thanks to

Code: Select all

zmprov modifyAccount user@example.net zimbraMailSieveScript "$(dump_sieve_one.txt)"

you should be able to add them one by one till you find out which one is the culprit.

Then you should write down a minimal set of steps to trigger this bug and share it with us.
I think that this bug somehow also affects NE.

3) According to the logs I also suspect to this being related to a filter based on dates. Either a java JRE update has changed how it deals with dates, either Zimbra has changed something else or maybe your final user has changed its date settings from M/D/YYYY to D/M/YYYY (assuming that can be done in Preferences which I have no idea) and has not updated his filters afterwards.

If that later case was true... the conclusion would be that filters based on date should be saved in an universal way and not in a user specific way.

I'm curious to see what you find out.

[halfgaar]

1) My theory at the time of it being caused by deleted folders was untrue. It's the same bug, seemingly triggered by a certain filter configuration on upgrade.

2) I will experiment with that, thanks.

3) I heard back from the user that he indeed has a time based component in it. I don't know the details yet.